[asterisk-users] Incoming SIP Calls dumped to non-existent VM no matter what extensions.conf setup is used
Joe Wood
schmoe at gmail.com
Wed Aug 4 22:25:32 CDT 2010
On Wed, Aug 4, 2010 at 7:49 PM, Warren Selby <wcselby at selbytech.com> wrote:
> On Wed, Aug 4, 2010 at 9:25 PM, Joe Wood <schmoe at gmail.com> wrote:
>>
>> I don't see any
>>
>> On Wed, Aug 4, 2010 at 7:04 PM, Warren Selby <wcselby at selbytech.com>
>> wrote:
>> >
>> > You don't have any extensions in your default context that match the
>> > extension that your sip peer is dialing in on. 's' is not a default
>> > extension for SIP...try using _X., and see what you get. Bump up the
>> > CLI
>> > (core set verbose 10) and then repost a failed called attempt. Some SIP
>> > providers also use a + symbol in front of their inbound calls, so you
>> > may
>> > need to use _+X., instead.
>>
>> I don't see any call attempt/logs when I bump up the verbosity, and
>> when I check my verbose logs I show:
>>
>
> The next step would be to enable sip debug on the peer you're trying to
> receive calls from (sip set debug peer PEERNAME or sip set debug ip
> IPADDRESS). Then send another call inbound and see what's happening. As
> far as the 's' extension, that's the "start" extension, it's used when no
> other extension information is presented. Pretty much every SIP peer I've
> ever seen presents an extension when entering a context, and thus the 's'
> extension doesn't catch it. I've typically only seen 's' used in Macros and
> with inbound analog lines.
>
My experience with Asterisk in the past has been with inbound analog
lines so that would make sense :)
See if you spot anything weird here:
<--- SIP read from UDP:209.221.186.98:5060 --->
INVITE sip:s at 209.221.186.50 SIP/2.0
Record-Route: <sip:209.221.186.98;ftag=f7093e2d7e16a927d0816f6f5ed7aba4;lr>
Via: SIP/2.0/UDP
209.221.186.98;branch=z9hG4bK6b95.ae84c9620e19761029084a0f85255c29.0
Via: SIP/2.0/UDP
209.221.186.98:5071;branch=z9hG4bKf0a046579186bf058ba7783ed98a5a66;rport=5071
Max-Forwards: 16
From: 2538544199
<sip:2538544199 at 209.221.186.98>;tag=f7093e2d7e16a927d0816f6f5ed7aba4
To: <sip:2063161626 at 209.221.186.98>
Call-ID: ba711218-1ae3-122e-41bd-18a905721e58-b2b_1
CSeq: 200 INVITE
Contact: Anonymous <sip:2538544199 at 209.221.186.98:5071>
Expires: 300
User-Agent: Sippy Softswitch v2.0.80
cisco-GUID: 1225641884-3786690633-966044271-4144140181
h323-conf-id: 1225641884-3786690633-966044271-4144140181
Content-Length: 321
Content-Type: application/sdp
v=0
o=- 1280279699622 1280279699622 IN IP4 209.221.186.98
s=-
c=IN IP4 209.221.186.98
t=0 0
m=audio 60304 RTP/AVP 0
a=fmtp:4 bitrate=6300;annexa=no
a=rtpmap:96 iLBC/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=20
a=fmtp:18 annexb=no
a=rtpmap:98 telephone-event/8000
a=oldmediaip:208.76.155.20
a=nortpproxy:yes
<------------->
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
0 [ 35]: INVITE sip:s at 209.221.186.50 SIP/2.0
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
1 [ 75]: Record-Route:
<sip:209.221.186.98;ftag=f7093e2d7e16a927d0816f6f5ed7aba4;lr>
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
2 [ 85]: Via: SIP/2.0/UDP
209.221.186.98;branch=z9hG4bK6b95.ae84c9620e19761029084a0f85255c29.0
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
3 [ 94]: Via: SIP/2.0/UDP
209.221.186.98:5071;branch=z9hG4bKf0a046579186bf058ba7783ed98a5a66;rport=5071
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
4 [ 16]: Max-Forwards: 16
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
5 [ 85]: From: 2538544199
<sip:2538544199 at 209.221.186.98>;tag=f7093e2d7e16a927d0816f6f5ed7aba4
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
6 [ 35]: To: <sip:2063161626 at 209.221.186.98>
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
7 [ 51]: Call-ID: ba711218-1ae3-122e-41bd-18a905721e58-b2b_1
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
8 [ 16]: CSeq: 200 INVITE
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
9 [ 55]: Contact: Anonymous <sip:2538544199 at 209.221.186.98:5071>
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
10 [ 12]: Expires: 300
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
11 [ 36]: User-Agent: Sippy Softswitch v2.0.80
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
12 [ 54]: cisco-GUID: 1225641884-3786690633-966044271-4144140181
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
13 [ 56]: h323-conf-id: 1225641884-3786690633-966044271-4144140181
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
14 [ 19]: Content-Length: 321
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
15 [ 29]: Content-Type: application/sdp
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
16 [ 0]:
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
0 [ 3]: v=0
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
1 [ 53]: o=- 1280279699622 1280279699622 IN IP4 209.221.186.98
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
2 [ 3]: s=-
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
3 [ 23]: c=IN IP4 209.221.186.98
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
4 [ 5]: t=0 0
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
5 [ 23]: m=audio 60304 RTP/AVP 0
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
6 [ 31]: a=fmtp:4 bitrate=6300;annexa=no
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
7 [ 21]: a=rtpmap:96 iLBC/8000
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
8 [ 21]: a=rtpmap:97 iLBC/8000
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
9 [ 17]: a=fmtp:97 mode=20
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
10 [ 19]: a=fmtp:18 annexb=no
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
11 [ 32]: a=rtpmap:98 telephone-event/8000
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
12 [ 26]: a=oldmediaip:208.76.155.20
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
13 [ 16]: a=nortpproxy:yes
--- (16 headers 14 lines) ---
[Aug 4 20:21:40] DEBUG[12487]: acl.c:507 ast_ouraddrfor: Found IP
address for this socket
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:3680 ast_sip_ouraddrfor:
Setting SIP_TRANSPORT_UDP with address 209.221.186.50:5060
== Using SIP RTP CoS mark 5
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:5009 do_setnat: Setting NAT
on RTP to Off
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7331 sip_alloc: Allocating
new SIP dialog for ba711218-1ae3-122e-41bd-18a905721e58-b2b_1 - INVITE
(With RTP)
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:21746 handle_incoming: ****
Received INVITE (5) - Command in SIP INVITE
Sending to 209.221.186.98 : 5060 (no NAT)
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:20036
handle_request_invite: Initializing initreq for method INVITE - callid
ba711218-1ae3-122e-41bd-18a905721e58-b2b_1
Using INVITE request as basis request -
ba711218-1ae3-122e-41bd-18a905721e58-b2b_1
Found peer '2063161626' for '2538544199' from 209.221.186.98:5060
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:5009 do_setnat: Setting NAT
on RTP to Off
<--- Reliably Transmitting (no NAT) to 209.221.186.98:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP
209.221.186.98;branch=z9hG4bK6b95.ae84c9620e19761029084a0f85255c29.0;received=209.221.186.98
Via: SIP/2.0/UDP
209.221.186.98:5071;branch=z9hG4bKf0a046579186bf058ba7783ed98a5a66;rport=5071
From: 2538544199
<sip:2538544199 at 209.221.186.98>;tag=f7093e2d7e16a927d0816f6f5ed7aba4
To: <sip:2063161626 at 209.221.186.98>;tag=as7e1288ea
Call-ID: ba711218-1ae3-122e-41bd-18a905721e58-b2b_1
CSeq: 200 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="asterisk", nonce="7f38497c"
Content-Length: 0
<------------>
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:3911 __sip_reliable_xmit:
*** SIP TIMER: Initializing retransmit timer on packet: Id #103
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:3559 __sip_xmit: Trying to
put 'SIP/2.0 401' onto UDP socket destined for 209.221.186.98:5060
Scheduling destruction of SIP dialog
'ba711218-1ae3-122e-41bd-18a905721e58-b2b_1' in 6400 ms (Method:
INVITE)
<--- SIP read from UDP:209.221.186.98:5060 --->
ACK sip:s at 209.221.186.50 SIP/2.0
Via: SIP/2.0/UDP
209.221.186.98;branch=z9hG4bK6b95.ae84c9620e19761029084a0f85255c29.0
From: 2538544199
<sip:2538544199 at 209.221.186.98>;tag=f7093e2d7e16a927d0816f6f5ed7aba4
Call-ID: ba711218-1ae3-122e-41bd-18a905721e58-b2b_1
To: <sip:2063161626 at 209.221.186.98>;tag=as7e1288ea
CSeq: 200 ACK
User-Agent: Sippy Softswitch v2.0.80
Content-Length: 0
<------------->
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
0 [ 32]: ACK sip:s at 209.221.186.50 SIP/2.0
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
1 [ 85]: Via: SIP/2.0/UDP
209.221.186.98;branch=z9hG4bK6b95.ae84c9620e19761029084a0f85255c29.0
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
2 [ 85]: From: 2538544199
<sip:2538544199 at 209.221.186.98>;tag=f7093e2d7e16a927d0816f6f5ed7aba4
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
3 [ 51]: Call-ID: ba711218-1ae3-122e-41bd-18a905721e58-b2b_1
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
4 [ 50]: To: <sip:2063161626 at 209.221.186.98>;tag=as7e1288ea
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
5 [ 13]: CSeq: 200 ACK
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
6 [ 36]: User-Agent: Sippy Softswitch v2.0.80
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
7 [ 17]: Content-Length: 0
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
8 [ 0]:
--- (8 headers 0 lines) ---
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:21746 handle_incoming: ****
Received ACK (6) - Command in SIP ACK
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:4063 __sip_ack: ** SIP
TIMER: Cancelling retransmit of packet (reply received) Retransid #103
[Aug 4 20:21:40] DEBUG[12487]: chan_sip.c:4095 __sip_ack: Stopping
retransmission on 'ba711218-1ae3-122e-41bd-18a905721e58-b2b_1' of
Response 200: Match Found
[Aug 4 20:21:46] DEBUG[12487]: chan_sip.c:3982 __sip_autodestruct:
Auto destroying SIP dialog
'ba711218-1ae3-122e-41bd-18a905721e58-b2b_1'
[Aug 4 20:21:46] DEBUG[12487]: chan_sip.c:5797 sip_destroy:
Destroying SIP dialog ba711218-1ae3-122e-41bd-18a905721e58-b2b_1
Really destroying SIP dialog
'ba711218-1ae3-122e-41bd-18a905721e58-b2b_1' Method: ACK
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7331 sip_alloc: Allocating
new SIP dialog for 597dcb344d527b453b57add96a3185e7 at 127.0.0.1 -
OPTIONS (No RTP)
[Aug 4 20:22:06] DEBUG[12487]: acl.c:507 ast_ouraddrfor: Found IP
address for this socket
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:3680 ast_sip_ouraddrfor:
Setting SIP_TRANSPORT_UDP with address 209.221.186.50:5060
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:3272 initialize_initreq:
Initializing initreq for method OPTIONS - callid
35d8fed95a19b7e37f44af1e1e6ac522 at 209.221.186.50
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
0 [ 34]: OPTIONS sip:209.221.186.98 SIP/2.0
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
1 [ 65]: Via: SIP/2.0/UDP
209.221.186.50:5060;branch=z9hG4bK3fb6b722;rport
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
2 [ 16]: Max-Forwards: 70
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
3 [ 61]: From: "asterisk"
<sip:asterisk at 209.221.186.50>;tag=as53dfbcc3
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
4 [ 24]: To: <sip:209.221.186.98>
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
5 [ 38]: Contact: <sip:asterisk at 209.221.186.50>
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
6 [ 56]: Call-ID: 35d8fed95a19b7e37f44af1e1e6ac522 at 209.221.186.50
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
7 [ 17]: CSeq: 102 OPTIONS
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
8 [ 33]: User-Agent: Asterisk PBX 1.6.2.10
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
9 [ 35]: Date: Thu, 05 Aug 2010 03:22:06 GMT
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE,
NOTIFY, INFO
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
11 [ 26]: Supported: replaces, timer
Reliably Transmitting (no NAT) to 209.221.186.98:5060:
OPTIONS sip:209.221.186.98 SIP/2.0
Via: SIP/2.0/UDP 209.221.186.50:5060;branch=z9hG4bK3fb6b722;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk at 209.221.186.50>;tag=as53dfbcc3
To: <sip:209.221.186.98>
Contact: <sip:asterisk at 209.221.186.50>
Call-ID: 35d8fed95a19b7e37f44af1e1e6ac522 at 209.221.186.50
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.2.10
Date: Thu, 05 Aug 2010 03:22:06 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
---
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:3911 __sip_reliable_xmit:
*** SIP TIMER: Initializing retransmit timer on packet: Id #105
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:3559 __sip_xmit: Trying to
put 'OPTIONS sip' onto UDP socket destined for 209.221.186.98:5060
<--- SIP read from UDP:209.221.186.98:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 209.221.186.50:5060;branch=z9hG4bK3fb6b722;rport=5060
From: "asterisk" <sip:asterisk at 209.221.186.50>;tag=as53dfbcc3
To: <sip:209.221.186.98>;tag=6c92f7145011cb1d75f5a124a939651b.5b09
Call-ID: 35d8fed95a19b7e37f44af1e1e6ac522 at 209.221.186.50
CSeq: 102 OPTIONS
Server: Sippy Softswitch v2.0.80
Content-Length: 0
<------------->
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
0 [ 14]: SIP/2.0 200 OK
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
1 [ 70]: Via: SIP/2.0/UDP
209.221.186.50:5060;branch=z9hG4bK3fb6b722;rport=5060
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
2 [ 61]: From: "asterisk"
<sip:asterisk at 209.221.186.50>;tag=as53dfbcc3
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
3 [ 66]: To: <sip:209.221.186.98>;tag=6c92f7145011cb1d75f5a124a939651b.5b09
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
4 [ 56]: Call-ID: 35d8fed95a19b7e37f44af1e1e6ac522 at 209.221.186.50
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
5 [ 17]: CSeq: 102 OPTIONS
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
6 [ 32]: Server: Sippy Softswitch v2.0.80
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
7 [ 17]: Content-Length: 0
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
8 [ 0]:
--- (8 headers 0 lines) ---
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:4063 __sip_ack: ** SIP
TIMER: Cancelling retransmit of packet (reply received) Retransid #105
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:4095 __sip_ack: Stopping
retransmission on '35d8fed95a19b7e37f44af1e1e6ac522 at 209.221.186.50' of
Request 102: Match Found
[Aug 4 20:22:06] DEBUG[12487]: chan_sip.c:5797 sip_destroy:
Destroying SIP dialog 35d8fed95a19b7e37f44af1e1e6ac522 at 209.221.186.50
Really destroying SIP dialog
'35d8fed95a19b7e37f44af1e1e6ac522 at 209.221.186.50' Method: OPTIONS
<--- SIP read from UDP:209.221.186.98:5060 --->
NOTIFY sip:s at 209.221.186.50 SIP/2.0
Via: SIP/2.0/UDP
209.221.186.98;branch=z9hG4bKad4e.7ae9f515798815474f58f362f1fb9711.0
Via: SIP/2.0/UDP
209.221.186.98:5061;branch=z9hG4bKb099faff323782a1776ca4ed0644c2a5;rport=5061
Max-Forwards: 16
From: Anonymous <sip:209.221.186.98:5061>;tag=6129c668eb36f859e29592f04b32edf8
To: <sip:2063161626 at 209.221.186.98:5060>
Call-ID: 38a5d175c85cf754fde3d4f869a29db5 at 209.221.186.98
CSeq: 1 NOTIFY
User-Agent: Sippy Softswitch v2.0.80
Event: message-summary
Content-Length: 23
Content-Type: application/simple-message-summary
Messages-Waiting: yes
<------------->
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
0 [ 35]: NOTIFY sip:s at 209.221.186.50 SIP/2.0
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
1 [ 85]: Via: SIP/2.0/UDP
209.221.186.98;branch=z9hG4bKad4e.7ae9f515798815474f58f362f1fb9711.0
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
2 [ 94]: Via: SIP/2.0/UDP
209.221.186.98:5061;branch=z9hG4bKb099faff323782a1776ca4ed0644c2a5;rport=5061
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
3 [ 16]: Max-Forwards: 16
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
4 [ 78]: From: Anonymous
<sip:209.221.186.98:5061>;tag=6129c668eb36f859e29592f04b32edf8
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
5 [ 40]: To: <sip:2063161626 at 209.221.186.98:5060>
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
6 [ 56]: Call-ID: 38a5d175c85cf754fde3d4f869a29db5 at 209.221.186.98
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
7 [ 14]: CSeq: 1 NOTIFY
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
8 [ 36]: User-Agent: Sippy Softswitch v2.0.80
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
9 [ 22]: Event: message-summary
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
10 [ 18]: Content-Length: 23
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
11 [ 48]: Content-Type: application/simple-message-summary
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
12 [ 0]:
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:7857 parse_request: Body
0 [ 21]: Messages-Waiting: yes
--- (12 headers 1 lines) ---
[Aug 4 20:22:17] DEBUG[12487]: acl.c:507 ast_ouraddrfor: Found IP
address for this socket
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:3680 ast_sip_ouraddrfor:
Setting SIP_TRANSPORT_UDP with address 209.221.186.50:5060
<--- Transmitting (no NAT) to 209.221.186.98:5060 --->
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP
209.221.186.98;branch=z9hG4bKad4e.7ae9f515798815474f58f362f1fb9711.0;received=209.221.186.98
Via: SIP/2.0/UDP
209.221.186.98:5061;branch=z9hG4bKb099faff323782a1776ca4ed0644c2a5;rport=5061
From: Anonymous <sip:209.221.186.98:5061>;tag=6129c668eb36f859e29592f04b32edf8
To: <sip:2063161626 at 209.221.186.98:5060>;tag=as78c1afb2
Call-ID: 38a5d175c85cf754fde3d4f869a29db5 at 209.221.186.98
CSeq: 1 NOTIFY
Server: Asterisk PBX 1.6.2.10
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
<------------>
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:3559 __sip_xmit: Trying to
put 'SIP/2.0 489' onto UDP socket destined for 209.221.186.98:5060
[Aug 4 20:22:17] DEBUG[12487]: chan_sip.c:22063 handle_request_do:
Invalid SIP message - rejected , no callid, len 591
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7331 sip_alloc: Allocating
new SIP dialog for 43995642065b6110482fdea36c4a1870 at 127.0.0.1 -
OPTIONS (No RTP)
[Aug 4 20:23:06] DEBUG[12487]: acl.c:507 ast_ouraddrfor: Found IP
address for this socket
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:3680 ast_sip_ouraddrfor:
Setting SIP_TRANSPORT_UDP with address 209.221.186.50:5060
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:3272 initialize_initreq:
Initializing initreq for method OPTIONS - callid
73352fce6cbc0df152db86ac2aaba3c7 at 209.221.186.50
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
0 [ 34]: OPTIONS sip:209.221.186.98 SIP/2.0
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
1 [ 65]: Via: SIP/2.0/UDP
209.221.186.50:5060;branch=z9hG4bK1510a8af;rport
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
2 [ 16]: Max-Forwards: 70
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
3 [ 61]: From: "asterisk"
<sip:asterisk at 209.221.186.50>;tag=as3ed8f247
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
4 [ 24]: To: <sip:209.221.186.98>
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
5 [ 38]: Contact: <sip:asterisk at 209.221.186.50>
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
6 [ 56]: Call-ID: 73352fce6cbc0df152db86ac2aaba3c7 at 209.221.186.50
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
7 [ 17]: CSeq: 102 OPTIONS
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
8 [ 33]: User-Agent: Asterisk PBX 1.6.2.10
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
9 [ 35]: Date: Thu, 05 Aug 2010 03:23:06 GMT
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE,
NOTIFY, INFO
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
11 [ 26]: Supported: replaces, timer
Reliably Transmitting (no NAT) to 209.221.186.98:5060:
OPTIONS sip:209.221.186.98 SIP/2.0
Via: SIP/2.0/UDP 209.221.186.50:5060;branch=z9hG4bK1510a8af;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk at 209.221.186.50>;tag=as3ed8f247
To: <sip:209.221.186.98>
Contact: <sip:asterisk at 209.221.186.50>
Call-ID: 73352fce6cbc0df152db86ac2aaba3c7 at 209.221.186.50
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.2.10
Date: Thu, 05 Aug 2010 03:23:06 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
---
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:3911 __sip_reliable_xmit:
*** SIP TIMER: Initializing retransmit timer on packet: Id #108
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:3559 __sip_xmit: Trying to
put 'OPTIONS sip' onto UDP socket destined for 209.221.186.98:5060
<--- SIP read from UDP:209.221.186.98:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 209.221.186.50:5060;branch=z9hG4bK1510a8af;rport=5060
From: "asterisk" <sip:asterisk at 209.221.186.50>;tag=as3ed8f247
To: <sip:209.221.186.98>;tag=6c92f7145011cb1d75f5a124a939651b.bc4b
Call-ID: 73352fce6cbc0df152db86ac2aaba3c7 at 209.221.186.50
CSeq: 102 OPTIONS
Server: Sippy Softswitch v2.0.80
Content-Length: 0
<------------->
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
0 [ 14]: SIP/2.0 200 OK
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
1 [ 70]: Via: SIP/2.0/UDP
209.221.186.50:5060;branch=z9hG4bK1510a8af;rport=5060
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
2 [ 61]: From: "asterisk"
<sip:asterisk at 209.221.186.50>;tag=as3ed8f247
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
3 [ 66]: To: <sip:209.221.186.98>;tag=6c92f7145011cb1d75f5a124a939651b.bc4b
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
4 [ 56]: Call-ID: 73352fce6cbc0df152db86ac2aaba3c7 at 209.221.186.50
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
5 [ 17]: CSeq: 102 OPTIONS
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
6 [ 32]: Server: Sippy Softswitch v2.0.80
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
7 [ 17]: Content-Length: 0
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
8 [ 0]:
--- (8 headers 0 lines) ---
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:4063 __sip_ack: ** SIP
TIMER: Cancelling retransmit of packet (reply received) Retransid #108
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:4095 __sip_ack: Stopping
retransmission on '73352fce6cbc0df152db86ac2aaba3c7 at 209.221.186.50' of
Request 102: Match Found
[Aug 4 20:23:06] DEBUG[12487]: chan_sip.c:5797 sip_destroy:
Destroying SIP dialog 73352fce6cbc0df152db86ac2aaba3c7 at 209.221.186.50
Really destroying SIP dialog
'73352fce6cbc0df152db86ac2aaba3c7 at 209.221.186.50' Method: OPTIONS
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7331 sip_alloc: Allocating
new SIP dialog for 1546988a7d38e4cb7514c3e5699546c1 at 127.0.0.1 -
OPTIONS (No RTP)
[Aug 4 20:24:06] DEBUG[12487]: acl.c:507 ast_ouraddrfor: Found IP
address for this socket
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:3680 ast_sip_ouraddrfor:
Setting SIP_TRANSPORT_UDP with address 209.221.186.50:5060
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:3272 initialize_initreq:
Initializing initreq for method OPTIONS - callid
21f2d7df10675b9512d6267f4889391b at 209.221.186.50
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
0 [ 34]: OPTIONS sip:209.221.186.98 SIP/2.0
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
1 [ 65]: Via: SIP/2.0/UDP
209.221.186.50:5060;branch=z9hG4bK54105de1;rport
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
2 [ 16]: Max-Forwards: 70
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
3 [ 61]: From: "asterisk"
<sip:asterisk at 209.221.186.50>;tag=as62c2ba21
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
4 [ 24]: To: <sip:209.221.186.98>
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
5 [ 38]: Contact: <sip:asterisk at 209.221.186.50>
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
6 [ 56]: Call-ID: 21f2d7df10675b9512d6267f4889391b at 209.221.186.50
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
7 [ 17]: CSeq: 102 OPTIONS
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
8 [ 33]: User-Agent: Asterisk PBX 1.6.2.10
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
9 [ 35]: Date: Thu, 05 Aug 2010 03:24:06 GMT
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE,
NOTIFY, INFO
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
11 [ 26]: Supported: replaces, timer
Reliably Transmitting (no NAT) to 209.221.186.98:5060:
OPTIONS sip:209.221.186.98 SIP/2.0
Via: SIP/2.0/UDP 209.221.186.50:5060;branch=z9hG4bK54105de1;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk at 209.221.186.50>;tag=as62c2ba21
To: <sip:209.221.186.98>
Contact: <sip:asterisk at 209.221.186.50>
Call-ID: 21f2d7df10675b9512d6267f4889391b at 209.221.186.50
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.2.10
Date: Thu, 05 Aug 2010 03:24:06 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
---
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:3911 __sip_reliable_xmit:
*** SIP TIMER: Initializing retransmit timer on packet: Id #111
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:3559 __sip_xmit: Trying to
put 'OPTIONS sip' onto UDP socket destined for 209.221.186.98:5060
<--- SIP read from UDP:209.221.186.98:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 209.221.186.50:5060;branch=z9hG4bK54105de1;rport=5060
From: "asterisk" <sip:asterisk at 209.221.186.50>;tag=as62c2ba21
To: <sip:209.221.186.98>;tag=6c92f7145011cb1d75f5a124a939651b.02df
Call-ID: 21f2d7df10675b9512d6267f4889391b at 209.221.186.50
CSeq: 102 OPTIONS
Server: Sippy Softswitch v2.0.80
Content-Length: 0
<------------->
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
0 [ 14]: SIP/2.0 200 OK
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
1 [ 70]: Via: SIP/2.0/UDP
209.221.186.50:5060;branch=z9hG4bK54105de1;rport=5060
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
2 [ 61]: From: "asterisk"
<sip:asterisk at 209.221.186.50>;tag=as62c2ba21
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
3 [ 66]: To: <sip:209.221.186.98>;tag=6c92f7145011cb1d75f5a124a939651b.02df
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
4 [ 56]: Call-ID: 21f2d7df10675b9512d6267f4889391b at 209.221.186.50
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
5 [ 17]: CSeq: 102 OPTIONS
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
6 [ 32]: Server: Sippy Softswitch v2.0.80
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
7 [ 17]: Content-Length: 0
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:7857 parse_request: Header
8 [ 0]:
--- (8 headers 0 lines) ---
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:4063 __sip_ack: ** SIP
TIMER: Cancelling retransmit of packet (reply received) Retransid #111
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:4095 __sip_ack: Stopping
retransmission on '21f2d7df10675b9512d6267f4889391b at 209.221.186.50' of
Request 102: Match Found
[Aug 4 20:24:06] DEBUG[12487]: chan_sip.c:5797 sip_destroy:
Destroying SIP dialog 21f2d7df10675b9512d6267f4889391b at 209.221.186.50
Really destroying SIP dialog
'21f2d7df10675b9512d6267f4889391b at 209.221.186.50' Method: OPTIONS
> --
> Thanks,
> --Warren Selby
> http://www.selbytech.com
>
> --
> _____________________________________________________________________
> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
> New to Asterisk? Join us for a live introductory webinar every Thurs:
> http://www.asterisk.org/hello
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
> http://lists.digium.com/mailman/listinfo/asterisk-users
>
More information about the asterisk-users
mailing list