[Aug 3 19:46:42] VERBOSE[22417] config.c: == Parsing '/etc/asterisk/logger.conf': [Aug 3 19:46:42] DEBUG[22417] config.c: Parsing /etc/asterisk/logger.conf [Aug 3 19:46:42] VERBOSE[22417] config.c: == Found [Aug 3 19:46:42] VERBOSE[22417] logger.c: Asterisk Event Logger restarted [Aug 3 19:46:42] VERBOSE[22417] logger.c: Asterisk Queue Logger restarted [Aug 3 19:46:49] DEBUG[22389] chan_sip.c: Auto destroying SIP dialog '03e5b6940ed0948a1b3f97cf13c51f76@voip.mainsoft.it' [Aug 3 19:46:49] DEBUG[22389] chan_sip.c: Destroying SIP dialog 03e5b6940ed0948a1b3f97cf13c51f76@voip.mainsoft.it [Aug 3 19:46:49] VERBOSE[22389] chan_sip.c: Really destroying SIP dialog '03e5b6940ed0948a1b3f97cf13c51f76@voip.mainsoft.it' Method: OPTIONS [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:[my local ip]:46286 ---> INVITE sip:00448701566366@94.124.69.4 SIP/2.0 Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-db69e83dbe431c70-1---d8754z-;rport Max-Forwards: 70 Contact: To: "00448701566366" From: "123";tag=c34c1542 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: X-Lite release 1104o stamp 56125 Content-Length: 436 v=0 o=- 4 2 IN IP4 [my local ip] s=CounterPath X-Lite 3.0 c=IN IP4 [my local ip] t=0 0 m=audio 65264 RTP/AVP 0 8 3 101 a=alt:1 1 : 0o0Nicgm rRqKXHzr [my local ip] 65264 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendrecv m=video 35166 RTP/AVP 115 34 a=alt:1 1 : waLd+LSo VB4+0AL4 [my local ip] 35166 a=fmtp:115 QCIF=1;CIF=1;I=1;J=1;T=1 a=fmtp:34 QCIF=1;CIF=1 a=rtpmap:115 H263-1998/90000 a=rtpmap:34 H263/90000 a=sendrecv <-------------> [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 0 [ 45]: INVITE sip:00448701566366@94.124.69.4 SIP/2.0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-db69e83dbe431c70-1---d8754z-;rport [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 3 [ 37]: Contact: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 4 [ 52]: To: "00448701566366" [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 5 [ 47]: From: "123";tag=c34c1542 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 6 [ 53]: Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 7 [ 14]: CSeq: 1 INVITE [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 10 [ 44]: User-Agent: X-Lite release 1104o stamp 56125 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 11 [ 19]: Content-Length: 436 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 12 [ 0]: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 0 [ 3]: v=0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 1 [ 25]: o=- 4 2 IN IP4 [my local ip] [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 2 [ 24]: s=CounterPath X-Lite 3.0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 3 [ 19]: c=IN IP4 [my local ip] [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 5 [ 31]: m=audio 65264 RTP/AVP 0 8 3 101 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 6 [ 46]: a=alt:1 1 : 0o0Nicgm rRqKXHzr [my local ip] 65264 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 7 [ 15]: a=fmtp:101 0-15 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 9 [ 10]: a=sendrecv [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 10 [ 28]: m=video 35166 RTP/AVP 115 34 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 11 [ 46]: a=alt:1 1 : waLd+LSo VB4+0AL4 [my local ip] 35166 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 12 [ 35]: a=fmtp:115 QCIF=1;CIF=1;I=1;J=1;T=1 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 13 [ 22]: a=fmtp:34 QCIF=1;CIF=1 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 14 [ 28]: a=rtpmap:115 H263-1998/90000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 15 [ 22]: a=rtpmap:34 H263/90000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 16 [ 10]: a=sendrecv [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: --- (12 headers 17 lines) --- [Aug 3 19:46:50] DEBUG[22389] acl.c: Found IP address for this socket [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 94.124.69.4:5060 [Aug 3 19:46:50] VERBOSE[22389] netsock.c: == Using SIP RTP TOS bits 184 [Aug 3 19:46:50] VERBOSE[22389] netsock.c: == Using SIP RTP CoS mark 5 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Setting NAT on RTP to Off [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Allocating new SIP dialog for YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. - INVITE (With RTP) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Sending to [my local ip] : 46286 (no NAT) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Initializing initreq for method INVITE - callid YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Using INVITE request as basis request - YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found peer '60061' for '60061' from [my local ip]:46286 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Setting NAT on RTP to Off [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: <--- Reliably Transmitting (no NAT) to [my local ip]:46286 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-db69e83dbe431c70-1---d8754z-;received=[my local ip];rport=46286 From: "123";tag=c34c1542 To: "00448701566366";tag=as3fcfbcf6 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 1 INVITE Server: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="voip.mainsoft.it", nonce="304a1549" Content-Length: 0 <------------> [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #119 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for [my local ip]:46286 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Scheduling destruction of SIP dialog 'YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE.' in 6656 ms (Method: INVITE) [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:[my local ip]:46286 ---> ACK sip:00448701566366@94.124.69.4 SIP/2.0 Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-db69e83dbe431c70-1---d8754z-;rport To: "00448701566366";tag=as3fcfbcf6 From: "123";tag=c34c1542 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 1 ACK Content-Length: 0 <-------------> [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 0 [ 42]: ACK sip:00448701566366@94.124.69.4 SIP/2.0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-db69e83dbe431c70-1---d8754z-;rport [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 2 [ 67]: To: "00448701566366";tag=as3fcfbcf6 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 3 [ 47]: From: "123";tag=c34c1542 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 5 [ 11]: CSeq: 1 ACK [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 7 [ 0]: [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: --- (7 headers 0 lines) --- [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #119 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Stopping retransmission on 'YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE.' of Response 1: Match Found [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:[my local ip]:46286 ---> INVITE sip:00448701566366@94.124.69.4 SIP/2.0 Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-b321140ebb171064-1---d8754z-;rport Max-Forwards: 70 Contact: To: "00448701566366" From: "123";tag=c34c1542 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: X-Lite release 1104o stamp 56125 Authorization: Digest username="60061",realm="voip.mainsoft.it",nonce="304a1549",uri="sip:00448701566366@94.124.69.4",response="01b6d69d947de161aeacb65bf37a0492",algorithm=MD5 Content-Length: 436 v=0 o=- 4 2 IN IP4 [my local ip] s=CounterPath X-Lite 3.0 c=IN IP4 [my local ip] t=0 0 m=audio 65264 RTP/AVP 0 8 3 101 a=alt:1 1 : 0o0Nicgm rRqKXHzr [my local ip] 65264 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendrecv m=video 35166 RTP/AVP 115 34 a=alt:1 1 : waLd+LSo VB4+0AL4 [my local ip] 35166 a=fmtp:115 QCIF=1;CIF=1;I=1;J=1;T=1 a=fmtp:34 QCIF=1;CIF=1 a=rtpmap:115 H263-1998/90000 a=rtpmap:34 H263/90000 a=sendrecv <-------------> [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 0 [ 45]: INVITE sip:00448701566366@94.124.69.4 SIP/2.0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-b321140ebb171064-1---d8754z-;rport [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 3 [ 37]: Contact: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 4 [ 52]: To: "00448701566366" [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 5 [ 47]: From: "123";tag=c34c1542 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 6 [ 53]: Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 7 [ 14]: CSeq: 2 INVITE [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 10 [ 44]: User-Agent: X-Lite release 1104o stamp 56125 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 11 [175]: Authorization: Digest username="60061",realm="voip.mainsoft.it",nonce="304a1549",uri="sip:00448701566366@94.124.69.4",response="01b6d69d947de161aeacb65bf37a0492",algorithm=MD5 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 12 [ 19]: Content-Length: 436 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 13 [ 0]: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 0 [ 3]: v=0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 1 [ 25]: o=- 4 2 IN IP4 [my local ip] [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 2 [ 24]: s=CounterPath X-Lite 3.0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 3 [ 19]: c=IN IP4 [my local ip] [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 5 [ 31]: m=audio 65264 RTP/AVP 0 8 3 101 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 6 [ 46]: a=alt:1 1 : 0o0Nicgm rRqKXHzr [my local ip] 65264 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 7 [ 15]: a=fmtp:101 0-15 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 9 [ 10]: a=sendrecv [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 10 [ 28]: m=video 35166 RTP/AVP 115 34 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 11 [ 46]: a=alt:1 1 : waLd+LSo VB4+0AL4 [my local ip] 35166 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 12 [ 35]: a=fmtp:115 QCIF=1;CIF=1;I=1;J=1;T=1 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 13 [ 22]: a=fmtp:34 QCIF=1;CIF=1 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 14 [ 28]: a=rtpmap:115 H263-1998/90000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 15 [ 22]: a=rtpmap:34 H263/90000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 16 [ 10]: a=sendrecv [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: --- (13 headers 17 lines) --- [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Sending to [my local ip] : 46286 (no NAT) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Initializing initreq for method INVITE - callid YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Using INVITE request as basis request - YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found peer '60061' for '60061' from [my local ip]:46286 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Setting NAT on RTP to Off [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP o=- 4 2 IN IP4 [my local ip]... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP s=CounterPath X-Lite 3.0... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP c=IN IP4 [my local ip]... OK. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP audio format 0 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP audio format 8 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP audio format 3 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP audio format 101 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=alt:1 1 : 0o0Nicgm rRqKXHzr [my local ip] 65264... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP video format 115 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP video format 34 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (video) SDP a=alt:1 1 : waLd+LSo VB4+0AL4 [my local ip] 35166... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (video) SDP a=fmtp:115 QCIF=1;CIF=1;I=1;J=1;T=1... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (video) SDP a=fmtp:34 QCIF=1;CIF=1... UNSUPPORTED. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found video description format H263-1998 for ID 115 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (video) SDP a=rtpmap:115 H263-1998/90000... OK. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found video description format H263 for ID 34 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (video) SDP a=rtpmap:34 H263/90000... OK. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (video) SDP a=sendrecv... OK. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Capabilities: us - 0xc7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14), peer - audio=0xe (gsm|ulaw|alaw)/video=0x180000 (h263|h263p)/text=0x0 (nothing), combined - 0x18000e (gsm|ulaw|alaw|h263|h263p) [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Peer audio RTP is at port [my local ip]:65264 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: We're settling with these formats: 0x18000e (gsm|ulaw|alaw|h263|h263p) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Checking SIP call limits for device 60061 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Updating call counter for incoming call [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Looking for 00448701566366 in customers (domain 94.124.69.4) [Aug 3 19:46:50] DEBUG[22389] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten = ? AND context = ? AND priority = ? [Aug 3 19:46:50] DEBUG[22389] res_config_odbc.c: Parameter 1 ('exten') = '00448701566366' [Aug 3 19:46:50] DEBUG[22389] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:50] DEBUG[22389] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:50] DEBUG[22389] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:50] DEBUG[22389] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten LIKE ? ESCAPE '\' AND context = ? AND priority = ? ORDER BY exten [Aug 3 19:46:50] DEBUG[22389] res_config_odbc.c: Parameter 1 ('exten LIKE') = '\_%' [Aug 3 19:46:50] DEBUG[22389] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:50] DEBUG[22389] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:50] DEBUG[22389] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: *** Our native formats are 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: *** Joint capabilities are 0x18000e (gsm|ulaw|alaw|h263|h263p) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: *** Our capabilities are 0xc7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: This channel will not be able to handle video. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: build_route: Contact hop: [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: list_route: hop: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Session timer started: 121 - YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: SIP/60061-0000000f: New call is still down.... Trying... [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: <--- Transmitting (no NAT) to [my local ip]:46286 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-b321140ebb171064-1---d8754z-;received=[my local ip];rport=46286 From: "123";tag=c34c1542 To: "00448701566366" Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for [my local ip]:46286 [Aug 3 19:46:50] DEBUG[22384] devicestate.c: No provider found, checking channel drivers for SIP - 60061 [Aug 3 19:46:50] DEBUG[22384] chan_sip.c: Checking device state for peer 60061 [Aug 3 19:46:50] DEBUG[22384] devicestate.c: Changing state for SIP/60061 - state 1 (Not in use) [Aug 3 19:46:50] DEBUG[22384] devicestate.c: device 'SIP/60061' state '1' [Aug 3 19:46:50] DEBUG[22388] app_queue.c: Device 'SIP/60061' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten = ? AND context = ? AND priority = ? [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten') = '00448701566366' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:50] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten LIKE ? ESCAPE '\' AND context = ? AND priority = ? ORDER BY exten [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten LIKE') = '\_%' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:50] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten = ? AND context = ? AND priority = ? [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten') = '00448701566366' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:50] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten LIKE ? ESCAPE '\' AND context = ? AND priority = ? ORDER BY exten [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten LIKE') = '\_%' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:50] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten = ? AND context = ? AND priority = ? [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten') = '00448701566366' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:50] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten LIKE ? ESCAPE '\' AND context = ? AND priority = ? ORDER BY exten [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten LIKE') = '\_%' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:50] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:50] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:50] VERBOSE[22432] pbx_realtime.c: -- Executing AGI("SIP/60061-0000000f", "MgrMain.php") [Aug 3 19:46:50] VERBOSE[22432] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/MgrMain.php [Aug 3 19:46:50] VERBOSE[22432] res_agi.c: -- AGI Script Executing Application: (Set) Options: (CHANNEL(language)=it) [Aug 3 19:46:50] VERBOSE[22432] res_agi.c: -- AGI Script Executing Application: (Dial) Options: (SIP/448701566366@PROVIDER1,120) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Asked to create a SIP channel with formats: 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:50] VERBOSE[22432] netsock.c: == Using SIP RTP TOS bits 184 [Aug 3 19:46:50] VERBOSE[22432] netsock.c: == Using SIP RTP CoS mark 5 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Allocating new SIP dialog for 2ff659da121dadd70fb7b4ae40ad81da@94.124.69.4 - INVITE (With RTP) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Setting NAT on RTP to Off [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Aug 3 19:46:50] DEBUG[22432] acl.c: Found IP address for this socket [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 94.124.69.4:5060 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** Our capabilities are 0x10e (gsm|ulaw|alaw|g729) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** Our preferred formats from the incoming channel are 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: This channel will not be able to handle video. [Aug 3 19:46:50] DEBUG[22432] rtp.c: Seeded SDP of 'SIP/PROVIDER1-00000010' with that of 'SIP/60061-0000000f' [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable DIALEDTIME. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable ANSWEREDTIME. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable DIALEDPEERNAME. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable DIALEDPEERNUMBER. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable DIALSTATUS. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable SIPCALLID. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable SIPDOMAIN. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable SIPURI. [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Outgoing Call for 448701566366 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Updating call counter for outgoing call [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: False Text flag: False [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: ** Our prefcodec: 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Audio is at 94.124.69.4 port 14386 [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x2 (gsm) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: -- Done with adding codecs to SDP [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Initializing initreq for method INVITE - callid 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 0 [ 43]: INVITE sip:448701566366@94.124.69.7 SIP/2.0 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 1 [ 62]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK4f69c9da;rport [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 3 [ 64]: From: "39025454104" ;tag=as52b25ca5 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 4 [ 34]: To: [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 5 [ 38]: Contact: [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 6 [ 53]: Call-ID: 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.10 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 9 [ 35]: Date: Tue, 03 Aug 2010 17:46:50 GMT [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 10 [ 20]: Session-Expires: 600 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 12 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Reliably Transmitting (no NAT) to 94.124.69.7:5060: INVITE sip:448701566366@94.124.69.7 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK4f69c9da;rport Max-Forwards: 70 From: "39025454104" ;tag=as52b25ca5 To: Contact: Call-ID: 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.2.10 Date: Tue, 03 Aug 2010 17:46:50 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 309 v=0 o=root 2113556688 2113556688 IN IP4 94.124.69.4 s=Asterisk PBX 1.6.2.10 c=IN IP4 94.124.69.4 t=0 0 m=audio 14386 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #123 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 94.124.69.7:5060 [Aug 3 19:46:50] VERBOSE[22432] app_dial.c: -- Called 448701566366@PROVIDER1 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.7:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK4f69c9da;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as52b25ca5 To: Call-ID: 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK4f69c9da;received=94.124.69.4;rport=5060 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as52b25ca5 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 3 [ 34]: To: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 9 [ 39]: Contact: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: --- (11 headers 0 lines) --- [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: *** SIP TIMER: Cancelling retransmission #123 - INVITE (got response) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4' Request 102: Found [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: SIP response 100 to standard invite [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.7:5060 ---> SIP/2.0 503 Service Unavailable Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK4f69c9da;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as52b25ca5 To: ;tag=as08aa0510 Call-ID: 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 0 [ 31]: SIP/2.0 503 Service Unavailable [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK4f69c9da;received=94.124.69.4;rport=5060 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as52b25ca5 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 3 [ 49]: To: ;tag=as08aa0510 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 9 [ 39]: Contact: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: --- (11 headers 0 lines) --- [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Acked pending invite 102 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Stopping retransmission on '2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4' of Request 102: Match Found [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: -- Got SIP response 503 "Service Unavailable" back from 94.124.69.7 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Transmitting (no NAT) to 94.124.69.7:5060: ACK sip:448701566366@94.124.69.7 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK4f69c9da;rport Max-Forwards: 70 From: "39025454104" ;tag=as52b25ca5 To: ;tag=as08aa0510 Contact: Call-ID: 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.2.10 Content-Length: 0 --- [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Trying to put 'ACK sip:448' onto UDP socket destined for 94.124.69.7:5060 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Setting SIP_ALREADYGONE on dialog 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 [Aug 3 19:46:50] VERBOSE[22432] app_dial.c: -- SIP/PROVIDER1-00000010 is circuit-busy [Aug 3 19:46:50] DEBUG[22432] channel.c: Hanging up channel 'SIP/PROVIDER1-00000010' [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Hangup call SIP/PROVIDER1-00000010, SIP callid 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 [Aug 3 19:46:50] DEBUG[22384] devicestate.c: No provider found, checking channel drivers for SIP - PROVIDER1 [Aug 3 19:46:50] DEBUG[22384] chan_sip.c: Checking device state for peer PROVIDER1 [Aug 3 19:46:50] DEBUG[22384] devicestate.c: Changing state for SIP/PROVIDER1 - state 1 (Not in use) [Aug 3 19:46:50] DEBUG[22384] devicestate.c: device 'SIP/PROVIDER1' state '1' [Aug 3 19:46:50] DEBUG[22388] app_queue.c: Device 'SIP/PROVIDER1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 3 19:46:50] VERBOSE[22432] app_dial.c: == Everyone is busy/congested at this time (1:0/1/0) [Aug 3 19:46:50] DEBUG[22432] rtp.c: Channel '' has no RTP, not doing anything [Aug 3 19:46:50] DEBUG[22432] app_dial.c: Exiting with DIALSTATUS=CONGESTION. ////////////////////////////////////////////////////////////////////////////////////////////////////////////////// ///// At this point the phpAgi script realize the congestion and retry the call trough the second provider ///// ///// DIALSTATUS CONGESTION - HANGUPCAUSE 34 ///// ////////////////////////////////////////////////////////////////////////////////////////////////////////////////// [Aug 3 19:46:50] VERBOSE[22432] res_agi.c: -- AGI Script Executing Application: (Dial) Options: (SIP/00448701566366@PROVIDER2,120) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Asked to create a SIP channel with formats: 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:50] VERBOSE[22432] netsock.c: == Using SIP RTP TOS bits 184 [Aug 3 19:46:50] VERBOSE[22432] netsock.c: == Using SIP RTP CoS mark 5 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Allocating new SIP dialog for 35995c0e18eebb3f3da19d165aacee8e@94.124.69.4 - INVITE (With RTP) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Setting NAT on RTP to Off [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Aug 3 19:46:50] DEBUG[22432] acl.c: Found IP address for this socket [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 94.124.69.4:5060 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** Our native formats are 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** Joint capabilities are 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** Our capabilities are 0xc7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** Our preferred formats from the incoming channel are 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: This channel will not be able to handle video. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Destroying SIP dialog 2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Really destroying SIP dialog '2644c8bf6bcbbcac497c4fdc2ab29041@94.124.69.4' Method: INVITE [Aug 3 19:46:50] DEBUG[22432] rtp.c: Seeded SDP of 'SIP/PROVIDER2-00000011' with that of 'SIP/60061-0000000f' [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable DIALEDTIME. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable ANSWEREDTIME. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable DIALEDPEERNAME. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable DIALEDPEERNUMBER. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable DIALSTATUS. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable SIPCALLID. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable SIPDOMAIN. [Aug 3 19:46:50] DEBUG[22432] channel.c: Not copying variable SIPURI. [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Outgoing Call for 00448701566366 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Updating call counter for outgoing call [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: This call needs video offers, but there's no video support enabled! [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: We think we can do text [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: This call needs text offers, but there's no text support enabled ! [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: ** Our capability: 0xc1898fe (gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g726aal2|g722|slin16|h263|h263p|red|t140) Video flag: False Text flag: False [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: ** Our prefcodec: 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Audio is at 94.124.69.4 port 16218 [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x2 (gsm) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x10 (g726aal2) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x20 (adpcm) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x40 (slin) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x80 (lpc10) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x800 (g726) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x1000 (g722) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x8000 (slin16) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: -- Done with adding codecs to SDP [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Done building SDP. Settling with this capability: 0xc1898fe (gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g726aal2|g722|slin16|h263|h263p|red|t140) [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Initializing initreq for method INVITE - callid 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 0 [ 50]: INVITE sip:00448701566366@94.124.69.5:5060 SIP/2.0 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 1 [ 62]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;rport [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 3 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 4 [ 41]: To: [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 5 [ 38]: Contact: [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 6 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.10 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 9 [ 35]: Date: Tue, 03 Aug 2010 17:46:50 GMT [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 10 [ 20]: Session-Expires: 600 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 12 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Reliably Transmitting (no NAT) to 94.124.69.5:5060: INVITE sip:00448701566366@94.124.69.5:5060 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;rport Max-Forwards: 70 From: "39025454104" ;tag=as56f97da6 To: Contact: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.2.10 Date: Tue, 03 Aug 2010 17:46:50 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 468 v=0 o=root 74480134 74480134 IN IP4 94.124.69.4 s=Asterisk PBX 1.6.2.10 c=IN IP4 94.124.69.4 t=0 0 m=audio 16218 RTP/AVP 0 8 3 112 5 10 7 111 9 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:112 AAL2-G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:10 L16/8000 a=rtpmap:7 LPC/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #125 [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 94.124.69.5:5060 [Aug 3 19:46:50] VERBOSE[22432] app_dial.c: -- Called 00448701566366@PROVIDER2 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;received=94.124.69.4;rport=5060 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 3 [ 41]: To: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: --- (11 headers 0 lines) --- [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: *** SIP TIMER: Cancelling retransmission #125 - INVITE (got response) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '05f763751344829f72fb5ff63743f894@94.124.69.4' Request 102: Found [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: SIP response 100 to standard invite [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 283 v=0 o=root 1993 1993 IN IP4 94.124.69.5 s=session c=IN IP4 94.124.69.5 t=0 0 m=audio 15834 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 0 [ 28]: SIP/2.0 183 Session Progress [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;received=94.124.69.4;rport=5060 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 11 [ 19]: Content-Length: 283 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Header 12 [ 0]: [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 0 [ 3]: v=0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 1 [ 35]: o=root 1993 1993 IN IP4 94.124.69.5 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 2 [ 9]: s=session [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 3 [ 20]: c=IN IP4 94.124.69.5 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 5 [ 31]: m=audio 15834 RTP/AVP 0 8 3 101 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 12 [ 10]: a=ptime:20 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Body 13 [ 10]: a=sendrecv [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: --- (12 headers 14 lines) --- [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '05f763751344829f72fb5ff63743f894@94.124.69.4' Request 102: Found [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: SIP response 183 to standard invite [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP o=root 1993 1993 IN IP4 94.124.69.5... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP s=session... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP c=IN IP4 94.124.69.5... OK. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP audio format 0 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP audio format 8 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP audio format 3 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found RTP audio format 101 [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found audio description format PCMU for ID 0 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found audio description format GSM for ID 3 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Capabilities: us - 0xc7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 3 19:46:50] VERBOSE[22389] chan_sip.c: Peer audio RTP is at port 94.124.69.5:15834 [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:50] DEBUG[22389] chan_sip.c: We have an owner, now see if we need to change this call [Aug 3 19:46:50] VERBOSE[22432] app_dial.c: -- SIP/PROVIDER2-00000011 is making progress passing it to SIP/60061-0000000f [Aug 3 19:46:50] DEBUG[22432] rtp.c: Setting early bridge SDP of 'SIP/60061-0000000f' with that of 'SIP/PROVIDER2-00000011' [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Setting framing from config on incoming call [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: This call needs video offers, but there's no video support enabled! [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: ** Our capability: 0x18000e (gsm|ulaw|alaw|h263|h263p) Video flag: False Text flag: True [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Audio is at 94.124.69.4 port 10162 [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding codec 0x2 (gsm) to SDP [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: -- Done with adding codecs to SDP [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Done building SDP. Settling with this capability: 0x18000e (gsm|ulaw|alaw|h263|h263p) [Aug 3 19:46:50] VERBOSE[22432] chan_sip.c: <--- Transmitting (no NAT) to [my local ip]:46286 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-b321140ebb171064-1---d8754z-;received=[my local ip];rport=46286 From: "123";tag=c34c1542 To: "00448701566366";tag=as33a7d077 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 333 v=0 o=root 703563422 703563422 IN IP4 94.124.69.4 s=Asterisk PBX 1.6.2.10 c=IN IP4 94.124.69.4 t=0 0 m=audio 10162 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv m=video 0 RTP/AVP 115 34 <------------> [Aug 3 19:46:50] DEBUG[22432] chan_sip.c: Trying to put 'SIP/2.0 183' onto UDP socket destined for [my local ip]:46286 [Aug 3 19:46:50] DEBUG[22432] rtp.c: Got RTCP report of 132 bytes [Aug 3 19:46:50] DEBUG[22432] rtp.c: Ooh, format changed from unknown to ulaw [Aug 3 19:46:50] DEBUG[22432] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Aug 3 19:46:50] DEBUG[22432] rtp.c: Ooh, format changed from unknown to ulaw [Aug 3 19:46:50] DEBUG[22432] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;received=94.124.69.4;rport=5060 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: --- (11 headers 0 lines) --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '05f763751344829f72fb5ff63743f894@94.124.69.4' Request 102: Found [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: SIP response 180 to standard invite [Aug 3 19:46:53] DEBUG[22384] devicestate.c: No provider found, checking channel drivers for SIP - PROVIDER2 [Aug 3 19:46:53] DEBUG[22384] chan_sip.c: Checking device state for peer PROVIDER2 [Aug 3 19:46:53] DEBUG[22384] devicestate.c: Changing state for SIP/PROVIDER2 - state 1 (Not in use) [Aug 3 19:46:53] DEBUG[22384] devicestate.c: device 'SIP/PROVIDER2' state '1' [Aug 3 19:46:53] DEBUG[22388] app_queue.c: Device 'SIP/PROVIDER2' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 3 19:46:53] VERBOSE[22432] app_dial.c: -- SIP/PROVIDER2-00000011 is ringing [Aug 3 19:46:53] DEBUG[22432] rtp.c: Setting early bridge SDP of 'SIP/60061-0000000f' with that of 'SIP/PROVIDER2-00000011' [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: <--- Transmitting (no NAT) to [my local ip]:46286 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-b321140ebb171064-1---d8754z-;received=[my local ip];rport=46286 From: "123";tag=c34c1542 To: "00448701566366";tag=as33a7d077 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for [my local ip]:46286 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 283 v=0 o=root 1993 1994 IN IP4 94.124.69.5 s=session c=IN IP4 94.124.69.5 t=0 0 m=audio 15834 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK42e023d8;received=94.124.69.4;rport=5060 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 11 [ 19]: Content-Length: 283 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 12 [ 0]: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 0 [ 3]: v=0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 1 [ 35]: o=root 1993 1994 IN IP4 94.124.69.5 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 2 [ 9]: s=session [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 3 [ 20]: c=IN IP4 94.124.69.5 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 5 [ 31]: m=audio 15834 RTP/AVP 0 8 3 101 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 12 [ 10]: a=ptime:20 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 13 [ 10]: a=sendrecv [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: --- (12 headers 14 lines) --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Acked pending invite 102 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Stopping retransmission on '05f763751344829f72fb5ff63743f894@94.124.69.4' of Request 102: Match Found [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: SIP response 200 to standard invite [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP o=root 1993 1994 IN IP4 94.124.69.5... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP s=session... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP c=IN IP4 94.124.69.5... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 0 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 8 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 3 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 101 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format PCMU for ID 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format GSM for ID 3 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Capabilities: us - 0xc7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Peer audio RTP is at port 94.124.69.5:15834 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: We have an owner, now see if we need to change this call [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Updating call counter for outgoing call [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: build_route: Contact hop: [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: list_route: hop: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Session timer started: 131 - 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Strict routing enforced for session 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: set destination to 94.124.69.5, port 5060 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Transmitting (no NAT) to 94.124.69.5:5060: ACK sip:00448701566366@94.124.69.5 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK13c4a506;rport Max-Forwards: 70 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Contact: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.2.10 Content-Length: 0 --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Trying to put 'ACK sip:004' onto UDP socket destined for 94.124.69.5:5060 [Aug 3 19:46:53] VERBOSE[22432] app_dial.c: -- SIP/PROVIDER2-00000011 answered SIP/60061-0000000f [Aug 3 19:46:53] DEBUG[22384] devicestate.c: No provider found, checking channel drivers for SIP - PROVIDER2 [Aug 3 19:46:53] DEBUG[22384] chan_sip.c: Checking device state for peer PROVIDER2 [Aug 3 19:46:53] DEBUG[22384] devicestate.c: Changing state for SIP/PROVIDER2 - state 1 (Not in use) [Aug 3 19:46:53] DEBUG[22384] devicestate.c: device 'SIP/PROVIDER2' state '1' [Aug 3 19:46:53] DEBUG[22388] app_queue.c: Device 'SIP/PROVIDER2' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 3 19:46:53] DEBUG[22432] rtp.c: Setting early bridge SDP of 'SIP/60061-0000000f' with that of 'SIP/PROVIDER2-00000011' [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: SIP answering channel: SIP/60061-0000000f [Aug 3 19:46:53] DEBUG[22432] rtp.c: Setting the marker bit due to a source update [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Setting framing from config on incoming call [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: This call needs video offers, but there's no video support enabled! [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: ** Our capability: 0x18000e (gsm|ulaw|alaw|h263|h263p) Video flag: False Text flag: True [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Audio is at 94.124.69.4 port 10162 [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding codec 0x2 (gsm) to SDP [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: -- Done with adding codecs to SDP [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Done building SDP. Settling with this capability: 0x18000e (gsm|ulaw|alaw|h263|h263p) [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: <--- Reliably Transmitting (no NAT) to [my local ip]:46286 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-b321140ebb171064-1---d8754z-;received=[my local ip];rport=46286 From: "123";tag=c34c1542 To: "00448701566366";tag=as33a7d077 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 333 v=0 o=root 703563422 703563423 IN IP4 94.124.69.4 s=Asterisk PBX 1.6.2.10 c=IN IP4 94.124.69.4 t=0 0 m=audio 10162 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv m=video 0 RTP/AVP 115 34 <------------> [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #132 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for [my local ip]:46286 [Aug 3 19:46:53] DEBUG[22432] features.c: bridge answer set, chan answer set [Aug 3 19:46:53] DEBUG[22432] rtp.c: Setting the marker bit due to a source update [Aug 3 19:46:53] DEBUG[22432] rtp.c: Setting the marker bit due to a source update [Aug 3 19:46:53] VERBOSE[22432] rtp.c: -- Native bridging SIP/60061-0000000f and SIP/PROVIDER2-00000011 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Deferring reinvite on SIP 'YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE.' - It's audio will be redirected to IP 94.124.69.5 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Sending reinvite on SIP '05f763751344829f72fb5ff63743f894@94.124.69.4' - It's audio soon redirected to IP [my local ip] [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Strict routing enforced for session 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: set_destination: set destination to 94.124.69.5, port 5060 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Text flag: True [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: ** Our prefcodec: 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Audio is at 94.124.69.4 port 16218 [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding codec 0x2 (gsm) to SDP [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: -- Done with adding codecs to SDP [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Initializing already initialized SIP dialog 05f763751344829f72fb5ff63743f894@94.124.69.4 (presumably reinvite) [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 0 [ 45]: INVITE sip:00448701566366@94.124.69.5 SIP/2.0 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 1 [ 62]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK062cc1e3;rport [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 3 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 4 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 5 [ 38]: Contact: [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 6 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 7 [ 16]: CSeq: 103 INVITE [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.10 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 9 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Reliably Transmitting (no NAT) to 94.124.69.5:5060: INVITE sip:00448701566366@94.124.69.5 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK062cc1e3;rport Max-Forwards: 70 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Contact: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 303 v=0 o=root 74480134 74480135 IN IP4 [my local ip] s=Asterisk PBX 1.6.2.10 c=IN IP4 [my local ip] t=0 0 m=audio 65264 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #133 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 94.124.69.5:5060 [Aug 3 19:46:53] DEBUG[22384] devicestate.c: No provider found, checking channel drivers for SIP - 60061 [Aug 3 19:46:53] DEBUG[22384] chan_sip.c: Checking device state for peer 60061 [Aug 3 19:46:53] DEBUG[22384] devicestate.c: Changing state for SIP/60061 - state 1 (Not in use) [Aug 3 19:46:53] DEBUG[22384] devicestate.c: device 'SIP/60061' state '1' [Aug 3 19:46:53] DEBUG[22388] app_queue.c: Device 'SIP/60061' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK062cc1e3;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 103 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK062cc1e3;received=94.124.69.4;rport=5060 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: --- (11 headers 0 lines) --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: *** SIP TIMER: Cancelling retransmission #133 - INVITE (got response) [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '05f763751344829f72fb5ff63743f894@94.124.69.4' Request 103: Found [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: SIP response 100 to RE-invite on outgoing call 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK062cc1e3;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 103 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 283 v=0 o=root 1993 1995 IN IP4 94.124.69.5 s=session c=IN IP4 94.124.69.5 t=0 0 m=audio 15834 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK062cc1e3;received=94.124.69.4;rport=5060 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 11 [ 19]: Content-Length: 283 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 12 [ 0]: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 0 [ 3]: v=0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 1 [ 35]: o=root 1993 1995 IN IP4 94.124.69.5 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 2 [ 9]: s=session [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 3 [ 20]: c=IN IP4 94.124.69.5 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 5 [ 31]: m=audio 15834 RTP/AVP 0 8 3 101 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 12 [ 10]: a=ptime:20 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 13 [ 10]: a=sendrecv [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: --- (12 headers 14 lines) --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Acked pending invite 103 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Stopping retransmission on '05f763751344829f72fb5ff63743f894@94.124.69.4' of Request 103: Match Found [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: SIP response 200 to RE-invite on outgoing call 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP o=root 1993 1995 IN IP4 94.124.69.5... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP s=session... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP c=IN IP4 94.124.69.5... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 0 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 8 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 3 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 101 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format PCMU for ID 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format GSM for ID 3 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Capabilities: us - 0xc7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Peer audio RTP is at port 94.124.69.5:15834 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: We have an owner, now see if we need to change this call [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Updating call counter for outgoing call [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Strict routing enforced for session 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: set destination to 94.124.69.5, port 5060 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Transmitting (no NAT) to 94.124.69.5:5060: ACK sip:00448701566366@94.124.69.5 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK57e65928;rport Max-Forwards: 70 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Contact: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 103 ACK User-Agent: Asterisk PBX 1.6.2.10 Content-Length: 0 --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Trying to put 'ACK sip:004' onto UDP socket destined for 94.124.69.5:5060 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:[my local ip]:46286 ---> ACK sip:00448701566366@94.124.69.4 SIP/2.0 Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-cb4a3c5b2c209a0e-1---d8754z-;rport Max-Forwards: 70 Contact: To: "00448701566366";tag=as33a7d077 From: "123";tag=c34c1542 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 2 ACK User-Agent: X-Lite release 1104o stamp 56125 Authorization: Digest username="60061",realm="voip.mainsoft.it",nonce="304a1549",uri="sip:00448701566366@94.124.69.4",response="01b6d69d947de161aeacb65bf37a0492",algorithm=MD5 Content-Length: 0 <-------------> [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 0 [ 42]: ACK sip:00448701566366@94.124.69.4 SIP/2.0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-cb4a3c5b2c209a0e-1---d8754z-;rport [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 3 [ 37]: Contact: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 4 [ 67]: To: "00448701566366";tag=as33a7d077 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 5 [ 47]: From: "123";tag=c34c1542 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 6 [ 53]: Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 7 [ 11]: CSeq: 2 ACK [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 8 [ 44]: User-Agent: X-Lite release 1104o stamp 56125 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 9 [175]: Authorization: Digest username="60061",realm="voip.mainsoft.it",nonce="304a1549",uri="sip:00448701566366@94.124.69.4",response="01b6d69d947de161aeacb65bf37a0492",algorithm=MD5 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: --- (11 headers 0 lines) --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #132 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Stopping retransmission on 'YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE.' of Response 2: Match Found [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Sending pending reinvite on 'YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE.' [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Strict routing enforced for session YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: set destination to [my local ip], port 46286 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: This call needs video offers, but there's no video support enabled! [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: ** Our capability: 0x18000e (gsm|ulaw|alaw|h263|h263p) Video flag: False Text flag: True [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Audio is at 94.124.69.4 port 10162 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Adding codec 0x2 (gsm) to SDP [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: -- Done with adding codecs to SDP [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Done building SDP. Settling with this capability: 0x18000e (gsm|ulaw|alaw|h263|h263p) [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Initializing already initialized SIP dialog YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. (presumably reinvite) [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 0 [ 41]: INVITE sip:60061@[my local ip]:46286 SIP/2.0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 1 [ 62]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK2b3ecb80;rport [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 3 [ 69]: From: "00448701566366";tag=as33a7d077 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 4 [ 45]: To: "123";tag=c34c1542 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 5 [ 41]: Contact: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 6 [ 53]: Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.10 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 9 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Reliably Transmitting (no NAT) to [my local ip]:46286: INVITE sip:60061@[my local ip]:46286 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK2b3ecb80;rport Max-Forwards: 70 From: "00448701566366";tag=as33a7d077 To: "123";tag=c34c1542 Contact: Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 307 v=0 o=root 703563422 703563424 IN IP4 94.124.69.5 s=Asterisk PBX 1.6.2.10 c=IN IP4 94.124.69.5 t=0 0 m=audio 15834 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #134 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for [my local ip]:46286 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:[my local ip]:46286 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK2b3ecb80;rport=5060 Contact: To: "123";tag=c34c1542 From: "00448701566366";tag=as33a7d077 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 102 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: X-Lite release 1104o stamp 56125 Content-Length: 183 v=0 o=- 4 3 IN IP4 [my local ip] s=CounterPath X-Lite 3.0 c=IN IP4 [my local ip] t=0 0 m=audio 65264 RTP/AVP 0 8 3 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendrecv <-------------> [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 1 [ 67]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK2b3ecb80;rport=5060 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 2 [ 37]: Contact: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 3 [ 45]: To: "123";tag=c34c1542 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 4 [ 69]: From: "00448701566366";tag=as33a7d077 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 5 [ 53]: Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 8 [ 29]: Content-Type: application/sdp [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 9 [ 44]: User-Agent: X-Lite release 1104o stamp 56125 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 10 [ 19]: Content-Length: 183 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 0 [ 3]: v=0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 1 [ 25]: o=- 4 3 IN IP4 [my local ip] [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 2 [ 24]: s=CounterPath X-Lite 3.0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 3 [ 19]: c=IN IP4 [my local ip] [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 5 [ 31]: m=audio 65264 RTP/AVP 0 8 3 101 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 6 [ 15]: a=fmtp:101 0-15 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 8 [ 10]: a=sendrecv [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: --- (11 headers 9 lines) --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Acked pending invite 102 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #134 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Stopping retransmission on 'YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE.' of Request 102: Match Found [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: SIP response 200 to RE-invite on outgoing call YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP o=- 4 3 IN IP4 [my local ip]... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP s=CounterPath X-Lite 3.0... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP c=IN IP4 [my local ip]... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 0 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 8 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 3 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 101 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Capabilities: us - 0xc7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Peer audio RTP is at port [my local ip]:65264 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: We have an owner, now see if we need to change this call [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Updating call counter for incoming call [Aug 3 19:46:53] DEBUG[22432] rtp.c: Oooh, 'SIP/60061-0000000f' changed end address to [my local ip]:65264 (format 14) [Aug 3 19:46:53] DEBUG[22432] rtp.c: Oooh, 'SIP/60061-0000000f' was [my local ip]:65264/(format 1572878) [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Sending reinvite on SIP '05f763751344829f72fb5ff63743f894@94.124.69.4' - It's audio soon redirected to IP [my local ip] [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Strict routing enforced for session 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: set_destination: set destination to 94.124.69.5, port 5060 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Text flag: True [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: ** Our prefcodec: 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Audio is at 94.124.69.4 port 16218 [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding codec 0x2 (gsm) to SDP [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: -- Done with adding codecs to SDP [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Initializing already initialized SIP dialog 05f763751344829f72fb5ff63743f894@94.124.69.4 (presumably reinvite) [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 0 [ 45]: INVITE sip:00448701566366@94.124.69.5 SIP/2.0 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 1 [ 62]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK6b857604;rport [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 3 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 4 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 5 [ 38]: Contact: [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 6 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 7 [ 16]: CSeq: 104 INVITE [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.10 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 9 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 3 19:46:53] VERBOSE[22432] chan_sip.c: Reliably Transmitting (no NAT) to 94.124.69.5:5060: INVITE sip:00448701566366@94.124.69.5 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK6b857604;rport Max-Forwards: 70 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Contact: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 104 INVITE User-Agent: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 303 v=0 o=root 74480134 74480136 IN IP4 [my local ip] s=Asterisk PBX 1.6.2.10 c=IN IP4 [my local ip] t=0 0 m=audio 65264 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #135 [Aug 3 19:46:53] DEBUG[22432] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 94.124.69.5:5060 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Strict routing enforced for session YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: set destination to [my local ip], port 46286 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Transmitting (no NAT) to [my local ip]:46286: ACK sip:60061@[my local ip]:46286 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK37487e4c;rport Max-Forwards: 70 From: "00448701566366";tag=as33a7d077 To: "123";tag=c34c1542 Contact: Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.2.10 Content-Length: 0 --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for [my local ip]:46286 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK6b857604;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 104 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK6b857604;received=94.124.69.4;rport=5060 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 104 INVITE [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: --- (11 headers 0 lines) --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: *** SIP TIMER: Cancelling retransmission #135 - INVITE (got response) [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '05f763751344829f72fb5ff63743f894@94.124.69.4' Request 104: Found [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: SIP response 100 to RE-invite on outgoing call 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK6b857604;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 104 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 283 v=0 o=root 1993 1996 IN IP4 94.124.69.5 s=session c=IN IP4 94.124.69.5 t=0 0 m=audio 15834 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK6b857604;received=94.124.69.4;rport=5060 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 104 INVITE [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 11 [ 19]: Content-Length: 283 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Header 12 [ 0]: [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 0 [ 3]: v=0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 1 [ 35]: o=root 1993 1996 IN IP4 94.124.69.5 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 2 [ 9]: s=session [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 3 [ 20]: c=IN IP4 94.124.69.5 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 5 [ 31]: m=audio 15834 RTP/AVP 0 8 3 101 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 12 [ 10]: a=ptime:20 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Body 13 [ 10]: a=sendrecv [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: --- (12 headers 14 lines) --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Acked pending invite 104 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Stopping retransmission on '05f763751344829f72fb5ff63743f894@94.124.69.4' of Request 104: Match Found [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: SIP response 200 to RE-invite on outgoing call 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP o=root 1993 1996 IN IP4 94.124.69.5... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP s=session... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP c=IN IP4 94.124.69.5... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 0 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 8 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 3 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found RTP audio format 101 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format PCMU for ID 0 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format GSM for ID 3 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Capabilities: us - 0xc7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Peer audio RTP is at port 94.124.69.5:15834 [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: We have an owner, now see if we need to change this call [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Updating call counter for outgoing call [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Strict routing enforced for session 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: set_destination: set destination to 94.124.69.5, port 5060 [Aug 3 19:46:53] VERBOSE[22389] chan_sip.c: Transmitting (no NAT) to 94.124.69.5:5060: ACK sip:00448701566366@94.124.69.5 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK40837676;rport Max-Forwards: 70 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Contact: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 104 ACK User-Agent: Asterisk PBX 1.6.2.10 Content-Length: 0 --- [Aug 3 19:46:53] DEBUG[22389] chan_sip.c: Trying to put 'ACK sip:004' onto UDP socket destined for 94.124.69.5:5060 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: ////////////////////////////////////////////////////////////////////////////////////////////////////////////////// ///// Here the called phone has anwered, i close the call with my softphone ///// ///// When the control returns to the agi script hangupcause is yet 34 , but dialstatus is ANSWER ///// ////////////////////////////////////////////////////////////////////////////////////////////////////////////////// <--- SIP read from UDP:[my local ip]:46286 ---> BYE sip:00448701566366@94.124.69.4 SIP/2.0 Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-864d6575f33f4b6d-1---d8754z-;rport Max-Forwards: 70 Contact: To: "00448701566366";tag=as33a7d077 From: "123";tag=c34c1542 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 3 BYE User-Agent: X-Lite release 1104o stamp 56125 Authorization: Digest username="60061",realm="voip.mainsoft.it",nonce="304a1549",uri="sip:00448701566366@94.124.69.4",response="acd3f17cec79d527cdb81d98ee53eca7",algorithm=MD5 Reason: SIP;description="User Hung Up" Content-Length: 0 <-------------> [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 0 [ 42]: BYE sip:00448701566366@94.124.69.4 SIP/2.0 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-864d6575f33f4b6d-1---d8754z-;rport [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 3 [ 37]: Contact: [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 4 [ 67]: To: "00448701566366";tag=as33a7d077 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 5 [ 47]: From: "123";tag=c34c1542 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 6 [ 53]: Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 7 [ 11]: CSeq: 3 BYE [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 8 [ 44]: User-Agent: X-Lite release 1104o stamp 56125 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 9 [175]: Authorization: Digest username="60061",realm="voip.mainsoft.it",nonce="304a1549",uri="sip:00448701566366@94.124.69.4",response="acd3f17cec79d527cdb81d98ee53eca7",algorithm=MD5 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 10 [ 38]: Reason: SIP;description="User Hung Up" [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 12 [ 0]: [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: --- (12 headers 0 lines) --- [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Initializing initreq for method BYE - callid YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Sending to [my local ip] : 46286 (no NAT) [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Setting SIP_ALREADYGONE on dialog YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Session timer stopped: -1 - YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Received bye, issuing owner hangup [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: <--- Transmitting (no NAT) to [my local ip]:46286 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP [my local ip]:46286;branch=z9hG4bK-d8754z-864d6575f33f4b6d-1---d8754z-;received=[my local ip];rport=46286 From: "123";tag=c34c1542 To: "00448701566366";tag=as33a7d077 Call-ID: YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. CSeq: 3 BYE Server: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for [my local ip]:46286 [Aug 3 19:46:55] DEBUG[22432] rtp.c: Oooh, got a hangup [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Sending reinvite on SIP '05f763751344829f72fb5ff63743f894@94.124.69.4' - It's audio soon redirected to IP 94.124.69.4 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Strict routing enforced for session 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: set_destination: set destination to 94.124.69.5, port 5060 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Text flag: True [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: ** Our prefcodec: 0x180004 (ulaw|h263|h263p) [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: Audio is at 94.124.69.4 port 16218 [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: Adding codec 0x2 (gsm) to SDP [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: -- Done with adding codecs to SDP [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Initializing already initialized SIP dialog 05f763751344829f72fb5ff63743f894@94.124.69.4 (presumably reinvite) [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 0 [ 45]: INVITE sip:00448701566366@94.124.69.5 SIP/2.0 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 1 [ 62]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK33b44c59;rport [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 3 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 4 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 5 [ 38]: Contact: [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 6 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 7 [ 16]: CSeq: 105 INVITE [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.10 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 9 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: Reliably Transmitting (no NAT) to 94.124.69.5:5060: INVITE sip:00448701566366@94.124.69.5 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK33b44c59;rport Max-Forwards: 70 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Contact: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 105 INVITE User-Agent: Asterisk PBX 1.6.2.10 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 305 v=0 o=root 74480134 74480137 IN IP4 94.124.69.4 s=Asterisk PBX 1.6.2.10 c=IN IP4 94.124.69.4 t=0 0 m=audio 16218 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #136 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 94.124.69.5:5060 [Aug 3 19:46:55] DEBUG[22432] channel.c: Returning from native bridge, channels: SIP/60061-0000000f, SIP/PROVIDER2-00000011 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK33b44c59;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 105 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK33b44c59;received=94.124.69.4;rport=5060 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 105 INVITE [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: --- (11 headers 0 lines) --- [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: *** SIP TIMER: Cancelling retransmission #136 - INVITE (got response) [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '05f763751344829f72fb5ff63743f894@94.124.69.4' Request 105: Found [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: SIP response 100 to RE-invite on outgoing call 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK33b44c59;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 105 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 283 v=0 o=root 1993 1997 IN IP4 94.124.69.5 s=session c=IN IP4 94.124.69.5 t=0 0 m=audio 15834 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK33b44c59;received=94.124.69.4;rport=5060 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 5 [ 16]: CSeq: 105 INVITE [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 11 [ 19]: Content-Length: 283 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 12 [ 0]: [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 0 [ 3]: v=0 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 1 [ 35]: o=root 1993 1997 IN IP4 94.124.69.5 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 2 [ 9]: s=session [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 3 [ 20]: c=IN IP4 94.124.69.5 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 5 [ 31]: m=audio 15834 RTP/AVP 0 8 3 101 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 12 [ 10]: a=ptime:20 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Body 13 [ 10]: a=sendrecv [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: --- (12 headers 14 lines) --- [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Acked pending invite 105 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Stopping retransmission on '05f763751344829f72fb5ff63743f894@94.124.69.4' of Request 105: Match Found [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: SIP response 200 to RE-invite on outgoing call 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing session-level SDP o=root 1993 1997 IN IP4 94.124.69.5... UNSUPPORTED. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing session-level SDP s=session... UNSUPPORTED. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing session-level SDP c=IN IP4 94.124.69.5... OK. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Found RTP audio format 0 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Found RTP audio format 8 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Found RTP audio format 3 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Found RTP audio format 101 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Found audio description format PCMU for ID 0 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Found audio description format GSM for ID 3 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Capabilities: us - 0xc7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Peer audio RTP is at port 94.124.69.5:15834 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: We have an owner, now see if we need to change this call [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Updating call counter for outgoing call [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Strict routing enforced for session 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: set_destination: set destination to 94.124.69.5, port 5060 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Transmitting (no NAT) to 94.124.69.5:5060: ACK sip:00448701566366@94.124.69.5 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK1b434a33;rport Max-Forwards: 70 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Contact: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 105 ACK User-Agent: Asterisk PBX 1.6.2.10 Content-Length: 0 --- [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Trying to put 'ACK sip:004' onto UDP socket destined for 94.124.69.5:5060 [Aug 3 19:46:55] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten = ? AND context = ? AND priority = ? [Aug 3 19:46:55] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten') = 'h' [Aug 3 19:46:55] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:55] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:55] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:55] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten LIKE ? ESCAPE '\' AND context = ? AND priority = ? ORDER BY exten [Aug 3 19:46:55] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten LIKE') = '\_%' [Aug 3 19:46:55] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:55] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:55] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:55] DEBUG[22432] channel.c: Hanging up channel 'SIP/PROVIDER2-00000011' [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Hangup call SIP/PROVIDER2-00000011, SIP callid 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: Scheduling destruction of SIP dialog '05f763751344829f72fb5ff63743f894@94.124.69.4' in 32000 ms (Method: INVITE) [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Session timer stopped: -1 - 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Strict routing enforced for session 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: set_destination: set destination to 94.124.69.5, port 5060 [Aug 3 19:46:55] VERBOSE[22432] chan_sip.c: Reliably Transmitting (no NAT) to 94.124.69.5:5060: BYE sip:00448701566366@94.124.69.5 SIP/2.0 Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK0ffe924d;rport Max-Forwards: 70 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 106 BYE User-Agent: Asterisk PBX 1.6.2.10 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #138 [Aug 3 19:46:55] DEBUG[22432] chan_sip.c: Trying to put 'BYE sip:004' onto UDP socket destined for 94.124.69.5:5060 [Aug 3 19:46:55] DEBUG[22384] devicestate.c: No provider found, checking channel drivers for SIP - PROVIDER2 [Aug 3 19:46:55] DEBUG[22384] chan_sip.c: Checking device state for peer PROVIDER2 [Aug 3 19:46:55] DEBUG[22384] devicestate.c: Changing state for SIP/PROVIDER2 - state 1 (Not in use) [Aug 3 19:46:55] DEBUG[22384] devicestate.c: device 'SIP/PROVIDER2' state '1' [Aug 3 19:46:55] DEBUG[22388] app_queue.c: Device 'SIP/PROVIDER2' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:94.124.69.5:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK0ffe924d;received=94.124.69.4;rport=5060 From: "39025454104" ;tag=as56f97da6 To: ;tag=as65b0bbcd Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 CSeq: 106 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 94.124.69.4:5060;branch=z9hG4bK0ffe924d;received=94.124.69.4;rport=5060 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 2 [ 64]: From: "39025454104" ;tag=as56f97da6 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 3 [ 56]: To: ;tag=as65b0bbcd [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 4 [ 53]: Call-ID: 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 5 [ 13]: CSeq: 106 BYE [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 8 [ 19]: Supported: replaces [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 9 [ 41]: Contact: [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Header 11 [ 0]: [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: --- (11 headers 0 lines) --- [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #138 [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Stopping retransmission on '05f763751344829f72fb5ff63743f894@94.124.69.4' of Request 106: Match Found [Aug 3 19:46:55] DEBUG[22389] chan_sip.c: Destroying SIP dialog 05f763751344829f72fb5ff63743f894@94.124.69.4 [Aug 3 19:46:55] VERBOSE[22389] chan_sip.c: Really destroying SIP dialog '05f763751344829f72fb5ff63743f894@94.124.69.4' Method: INVITE [Aug 3 19:46:55] DEBUG[22432] rtp.c: Channel '' has no RTP, not doing anything [Aug 3 19:46:55] DEBUG[22432] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Aug 3 19:46:55] DEBUG[22432] res_agi.c: SIP/60061-0000000f hungup [Aug 3 19:46:56] VERBOSE[22432] res_agi.c: -- AGI Script MgrMain.php completed, returning -1 [Aug 3 19:46:56] DEBUG[22432] pbx.c: Extension 00448701566366, priority 1 returned normally even though call was hung up [Aug 3 19:46:56] DEBUG[22432] channel.c: Soft-Hanging up channel 'SIP/60061-0000000f' [Aug 3 19:46:56] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten = ? AND context = ? AND priority = ? [Aug 3 19:46:56] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten') = 'h' [Aug 3 19:46:56] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:56] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:56] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:56] DEBUG[22432] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM mp_voipExtensions WHERE exten LIKE ? ESCAPE '\' AND context = ? AND priority = ? ORDER BY exten [Aug 3 19:46:56] DEBUG[22432] res_config_odbc.c: Parameter 1 ('exten LIKE') = '\_%' [Aug 3 19:46:56] DEBUG[22432] res_config_odbc.c: Parameter 2 ('context') = 'customers' [Aug 3 19:46:56] DEBUG[22432] res_config_odbc.c: Parameter 3 ('priority') = '1' [Aug 3 19:46:56] DEBUG[22432] res_odbc.c: odbc_release_obj2(0x81e21d0) called (obj->txf = (nil)) [Aug 3 19:46:56] DEBUG[22432] channel.c: Hanging up channel 'SIP/60061-0000000f' [Aug 3 19:46:56] DEBUG[22432] chan_sip.c: Hangup call SIP/60061-0000000f, SIP callid YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:56] DEBUG[22384] devicestate.c: No provider found, checking channel drivers for SIP - 60061 [Aug 3 19:46:56] DEBUG[22384] chan_sip.c: Checking device state for peer 60061 [Aug 3 19:46:56] DEBUG[22384] devicestate.c: Changing state for SIP/60061 - state 1 (Not in use) [Aug 3 19:46:56] DEBUG[22384] devicestate.c: device 'SIP/60061' state '1' [Aug 3 19:46:56] DEBUG[22388] app_queue.c: Device 'SIP/60061' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 3 19:46:56] DEBUG[22389] chan_sip.c: Destroying SIP dialog YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE. [Aug 3 19:46:56] VERBOSE[22389] chan_sip.c: Really destroying SIP dialog 'YjA4OWVhMDVjYzNjN2U0MGM5MDZlYzY5MTliNWM4NTE.' Method: BYE [Aug 3 19:47:06] VERBOSE[22389] chan_sip.c: <--- SIP read from UDP:[my local ip]:46286 ---> <------------->