Linksys SPA 942 problems

I have a little dilemma. I setup a VMWare Server, running on a Vista box. The Vista firewall is off. Asterisk v.1.4.11

Asterisk Server: 192.168.1.77
Linksys: 192.168.1.59

Sip.conf shows:

[100]
type=friend
host=dynamic
context=home
secret=xxxx
callerid=“Remzi Semsettin Turer” <100>
mailbox=100
nat=no
qualify=yes
disallow=all
allow=ulaw
allow=alaw
allow=g729
allow=g723
allow=gsm
allow=h263
allow=h264
dtmfmode=rfc2833
canreinvite=no
video=yes
restrictcid=no

The registration fails after a couple of minutes, and I noticed

chan_sip.c:15128 sipsock_read: Invalid SIP message - rejected , no callid, len 318

error messages on the console. Initially registration goes through, but after a while it starts failing (Linksys is set to re-register every 5 minutes). Below you can see some debug output. Any ideas what might be causing the error messages and registration failure?

<— SIP read from 192.168.1.59:5061 —>
REGISTER sip:192.168.1.77 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-da974cd6
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12935 REGISTER
Max-Forwards: 70
Contact: “Remzi Semsettin Turer” sip:100@192.168.1.59:5061;expires=300
User-Agent: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: REGISTER sip:192.168.1.77 SIP/2.0 (33)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-da974cd6 (58)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1 (75)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: To: “Remzi Semsettin Turer” sip:100@192.168.1.77 (50)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: Call-ID: db99328a-42ed9335@192.168.1.59 (39)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: CSeq: 12935 REGISTER (20)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Max-Forwards: 70 (16)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Contact: “Remzi Semsettin Turer” sip:100@192.168.1.59:5061;expires=300 (72)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: User-Agent: Linksys/SPA942-5.1.10 (33)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 11: Supported: replaces (19)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 12: (0)
— (12 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4450 sip_alloc: Allocating new SIP dialog for db99328a-42ed9335@192.168.1.59 - REGISTER (No RTP)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:14944 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
Using latest REGISTER request as basis request
Sending to 192.168.1.59 : 5061 (NAT)

<— Transmitting (no NAT) to 192.168.1.59:5061 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-da974cd6;received=192.168.1.59
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12935 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: sip:100@192.168.1.77
Content-Length: 0

<------------>

<— Transmitting (no NAT) to 192.168.1.59:5061 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-da974cd6;received=192.168.1.59
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=as7e82a748
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12935 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="5a8d600c"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘db99328a-42ed9335@192.168.1.59’ in 32000 ms (Method: REGISTER)

<— SIP read from 192.168.1.59:5061 —>
REGISTER sip:192.168.1.77 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-da974cd6
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12935 REGISTER
Max-Forwards: 70
Contact: “Remzi Semsettin Turer” sip:100@192.168.1.59:5061;expires=300
User-Agent: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: REGISTER sip:192.168.1.77 SIP/2.0 (33)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-da974cd6 (58)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1 (75)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: To: “Remzi Semsettin Turer” sip:100@192.168.1.77 (50)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: Call-ID: db99328a-42ed9335@192.168.1.59 (39)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: CSeq: 12935 REGISTER (20)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Max-Forwards: 70 (16)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Contact: “Remzi Semsettin Turer” sip:100@192.168.1.59:5061;expires=300 (72)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: User-Agent: Linksys/SPA942-5.1.10 (33)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 11: Supported: replaces (19)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 12: (0)
— (12 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: db99328a-42ed9335@192.168.1.59 Their Tag f52b0624b20747dao1 Our tag: as7e82a748
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:14944 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:14963 handle_request: Ignoring SIP message because of retransmit (REGISTER Seqno 12935, ours 12935)
Using latest REGISTER request as basis request
Sending to 192.168.1.59 : 5061 (no NAT)

<— Transmitting (no NAT) to 192.168.1.59:5061 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-da974cd6;received=192.168.1.59
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12935 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: sip:100@192.168.1.77
Content-Length: 0

<------------>

<— Transmitting (no NAT) to 192.168.1.59:5061 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-da974cd6;received=192.168.1.59
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=as7e82a748
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12935 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="5a8d600c"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘db99328a-42ed9335@192.168.1.59’ in 32000 ms (Method: REGISTER)
Asterisk*CLI>
<— SIP read from 192.168.1.59:5061 —>
REGISTER sip:192.168.1.77 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-3e07fd07
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12936 REGISTER
Max-Forwards: 70
Authorization: Digest username=“100”,realm=“asterisk”,nonce=“5a8d600c”,uri=“sip:192.168.1.77”,algorithm=MD5,response="546b5ba8ab31a596ae40b0e0ca1260ee"
Contact: “Remzi Semsettin Turer” sip:100@192.168.1.59:5061;expires=300
User-Agent: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: REGISTER sip:192.168.1.77 SIP/2.0 (33)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-3e07fd07 (58)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1 (75)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: To: “Remzi Semsettin Turer” sip:100@192.168.1.77 (50)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: Call-ID: db99328a-42ed9335@192.168.1.59 (39)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: CSeq: 12936 REGISTER (20)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Max-Forwards: 70 (16)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Authorization: Digest username=“100”,realm=“asterisk”,nonce=“5a8d600c”,uri=“sip:192.168.1.77”,algorithm=MD5,response=“546b5ba8ab31a596ae40b0e0ca1260ee” (151)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Contact: “Remzi Semsettin Turer” sip:100@192.168.1.59:5061;expires=300 (72)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: User-Agent: Linksys/SPA942-5.1.10 (33)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 12: Supported: replaces (19)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 13: (0)
— (13 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: db99328a-42ed9335@192.168.1.59 Their Tag f52b0624b20747dao1 Our tag: as7e82a748
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:14944 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
Using latest REGISTER request as basis request
Sending to 192.168.1.59 : 5061 (no NAT)

<— Transmitting (no NAT) to 192.168.1.59:5061 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-3e07fd07;received=192.168.1.59
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12936 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: sip:100@192.168.1.77
Content-Length: 0

<------------>
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4450 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: OPTIONS sip:100@192.168.1.59:5061 SIP/2.0 (41)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183;rport (63)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a (59)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: To: sip:100@192.168.1.59:5061 (31)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: Contact: sip:asterisk@192.168.1.77 (36)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: CSeq: 102 OPTIONS (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: User-Agent: Asterisk PBX (24)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Max-Forwards: 70 (16)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Date: Thu, 06 Sep 2007 01:55:13 GMT (35)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 11: Supported: replaces (19)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 12: Content-Length: 0 (17)
Reliably Transmitting (no NAT) to 192.168.1.59:5061:
OPTIONS sip:100@192.168.1.59:5061 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183;rport
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a
To: sip:100@192.168.1.59:5061
Contact: sip:asterisk@192.168.1.77
Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Thu, 06 Sep 2007 01:55:13 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


[Sep 5 21:55:13] DEBUG[4948]: sched.c:284 ast_sched_del: Attempted to delete nonexistent schedule entry 0!
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:2037 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #14951
– Registered SIP ‘100’ at 192.168.1.59 port 5061 expires 300

<— Transmitting (no NAT) to 192.168.1.59:5061 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-3e07fd07;received=192.168.1.59
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=as7e82a748
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12936 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Expires: 300
Contact: sip:100@192.168.1.59:5061;expires=300
Date: Thu, 06 Sep 2007 01:55:13 GMT
Content-Length: 0

<------------>
[Sep 5 21:55:13] DEBUG[4948]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100
Scheduling destruction of SIP dialog ‘db99328a-42ed9335@192.168.1.59’ in 32000 ms (Method: REGISTER)

<— SIP read from 192.168.1.59:5061 —>
REGISTER sip:192.168.1.77 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-3e07fd07
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12936 REGISTER
Max-Forwards: 70
Authorization: Digest username=“100”,realm=“asterisk”,nonce=“5a8d600c”,uri=“sip:192.168.1.77”,algorithm=MD5,response="546b5ba8ab31a596ae40b0e0ca1260ee"
Contact: “Remzi Semsettin Turer” sip:100@192.168.1.59:5061;expires=300
User-Agent: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: REGISTER sip:192.168.1.77 SIP/2.0 (33)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-3e07fd07 (58)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1 (75)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: To: “Remzi Semsettin Turer” sip:100@192.168.1.77 (50)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: Call-ID: db99328a-42ed9335@192.168.1.59 (39)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: CSeq: 12936 REGISTER (20)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Max-Forwards: 70 (16)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Authorization: Digest username=“100”,realm=“asterisk”,nonce=“5a8d600c”,uri=“sip:192.168.1.77”,algorithm=MD5,response=“546b5ba8ab31a596ae40b0e0ca1260ee” (151)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Contact: “Remzi Semsettin Turer” sip:100@192.168.1.59:5061;expires=300 (72)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: User-Agent: Linksys/SPA942-5.1.10 (33)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 12: Supported: replaces (19)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 13: (0)
— (13 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = No match Their Call ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77 Their Tag Our tag: as6835996a
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: db99328a-42ed9335@192.168.1.59 Their Tag f52b0624b20747dao1 Our tag: as7e82a748
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:14944 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:14963 handle_request: Ignoring SIP message because of retransmit (REGISTER Seqno 12936, ours 12936)
Using latest REGISTER request as basis request
Sending to 192.168.1.59 : 5061 (no NAT)

<— Transmitting (no NAT) to 192.168.1.59:5061 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-3e07fd07;received=192.168.1.59
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12936 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: sip:100@192.168.1.77
Content-Length: 0

<------------>
[Sep 5 21:55:13] DEBUG[4590]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100
[Sep 5 21:55:13] DEBUG[4590]: chan_sip.c:15574 sip_devicestate: Checking device state for peer 100
[Sep 5 21:55:13] DEBUG[4590]: devicestate.c:287 do_state_change: Changing state for SIP/100 - state 1 (Not in use)
[Sep 5 21:55:13] DEBUG[4590]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100
[Sep 5 21:55:13] DEBUG[4590]: chan_sip.c:15574 sip_devicestate: Checking device state for peer 100

<— Transmitting (no NAT) to 192.168.1.59:5061 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.59:5061;branch=z9hG4bK-3e07fd07;received=192.168.1.59
From: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=f52b0624b20747dao1
To: “Remzi Semsettin Turer” sip:100@192.168.1.77;tag=as7e82a748
Call-ID: db99328a-42ed9335@192.168.1.59
CSeq: 12936 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Expires: 300
Contact: sip:100@192.168.1.59:5061;expires=300
Date: Thu, 06 Sep 2007 01:55:13 GMT
Content-Length: 0

<------------>
[Sep 5 21:55:13] DEBUG[4948]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100
Scheduling destruction of SIP dialog ‘db99328a-42ed9335@192.168.1.59’ in 32000 ms (Method: REGISTER)
[Sep 5 21:55:13] DEBUG[6015]: app_queue.c:548 changethread: Device ‘SIP/100’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Sep 5 21:55:13] DEBUG[4590]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100
[Sep 5 21:55:13] DEBUG[4590]: chan_sip.c:15574 sip_devicestate: Checking device state for peer 100
[Sep 5 21:55:13] DEBUG[4590]: devicestate.c:287 do_state_change: Changing state for SIP/100 - state 1 (Not in use)
[Sep 5 21:55:13] DEBUG[4590]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100
[Sep 5 21:55:13] DEBUG[4590]: chan_sip.c:15574 sip_devicestate: Checking device state for peer 100
[Sep 5 21:55:13] DEBUG[6016]: app_queue.c:548 changethread: Device ‘SIP/100’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4450 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
Scheduling destruction of SIP dialog ‘483e9f472e4f272a76618bf802b2d4de@192.168.1.77’ in 32000 ms (Method: NOTIFY)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: NOTIFY sip:100@192.168.1.59:5061 SIP/2.0 (40)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK6710f704;rport (63)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as1aa07c64 (59)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: To: sip:100@192.168.1.59:5061 (31)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: Contact: sip:asterisk@192.168.1.77 (36)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Call-ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: CSeq: 102 NOTIFY (16)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: User-Agent: Asterisk PBX (24)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Max-Forwards: 70 (16)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Event: message-summary (22)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: Content-Type: application/simple-message-summary (48)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 11: Content-Length: 92 (18)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 12: (0)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4747 parse_request: Line: Messages-Waiting: no (20)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4747 parse_request: Line: Message-Account: sip:asterisk@192.168.1.77 (42)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4747 parse_request: Line: Voice-Message: 0/0 (0/0) (24)
Reliably Transmitting (no NAT) to 192.168.1.59:5061:
NOTIFY sip:100@192.168.1.59:5061 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK6710f704;rport
From: “asterisk” sip:asterisk@192.168.1.77;tag=as1aa07c64
To: sip:100@192.168.1.59:5061
Contact: sip:asterisk@192.168.1.77
Call-ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 92

Messages-Waiting: no
Message-Account: sip:asterisk@192.168.1.77
Voice-Message: 0/0 (0/0)


[Sep 5 21:55:13] DEBUG[4948]: sched.c:284 ast_sched_del: Attempted to delete nonexistent schedule entry 0!
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:2037 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #14957

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a
Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a (59)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183 (57)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = No match Their Call ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77 Their Tag Our tag: as1aa07c64
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77 Their Tag Our tag: as6835996a
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:2148 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #14951
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘20d4f8d37267e1087888ea850faf6463@192.168.1.77’ of Request 102: Match Not Found
[Sep 5 21:55:13] NOTICE[4948]: chan_sip.c:12331 handle_response_peerpoke: Peer ‘100’ is now Reachable. (12ms / 2000ms)
[Sep 5 21:55:13] DEBUG[4948]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a
Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a (59)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183 (57)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = No match Their Call ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77 Their Tag Our tag: as1aa07c64
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77 Their Tag 5e90d36cc0d69b32i1 Our tag: as6835996a
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘20d4f8d37267e1087888ea850faf6463@192.168.1.77’ of Request 102: Match Found
[Sep 5 21:55:13] DEBUG[4590]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100
[Sep 5 21:55:13] DEBUG[4590]: chan_sip.c:15574 sip_devicestate: Checking device state for peer 100
[Sep 5 21:55:13] DEBUG[4590]: devicestate.c:287 do_state_change: Changing state for SIP/100 - state 1 (Not in use)
[Sep 5 21:55:13] DEBUG[4590]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100
[Sep 5 21:55:13] DEBUG[4590]: chan_sip.c:15574 sip_devicestate: Checking device state for peer 100

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a
Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a (59)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183 (57)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = No match Their Call ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77 Their Tag Our tag: as1aa07c64
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77 Their Tag 5e90d36cc0d69b32i1 Our tag: as6835996a
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘20d4f8d37267e1087888ea850faf6463@192.168.1.77’ of Request 102: Match Found
Really destroying SIP dialog ‘20d4f8d37267e1087888ea850faf6463@192.168.1.77’ Method: OPTIONS

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a
Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6835996a (59)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 20d4f8d37267e1087888ea850faf6463@192.168.1.77 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK7ac2f183 (57)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = No match Their Call ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77 Their Tag Our tag: as1aa07c64
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = No match Their Call ID: db99328a-42ed9335@192.168.1.59 Their Tag f52b0624b20747dao1 Our tag: as7e82a748
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:15128 sipsock_read: Invalid SIP message - rejected , no callid, len 403
[Sep 5 21:55:13] DEBUG[6017]: app_queue.c:548 changethread: Device ‘SIP/100’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as1aa07c64
Call-ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77
CSeq: 102 NOTIFY
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK6710f704
Server: Linksys/SPA942-5.1.10
Content-Length: 0

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as1aa07c64 (59)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 NOTIFY (16)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK6710f704 (57)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: (0)
— (8 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77 Their Tag Our tag: as1aa07c64
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:2148 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #14957
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘483e9f472e4f272a76618bf802b2d4de@192.168.1.77’ of Request 102: Match Not Found
Really destroying SIP dialog ‘483e9f472e4f272a76618bf802b2d4de@192.168.1.77’ Method: NOTIFY

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as1aa07c64
Call-ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77
CSeq: 102 NOTIFY
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK6710f704
Server: Linksys/SPA942-5.1.10
Content-Length: 0

<------------->
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as1aa07c64 (59)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 483e9f472e4f272a76618bf802b2d4de@192.168.1.77 (54)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 NOTIFY (16)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK6710f704 (57)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: (0)
— (8 headers 0 lines) —
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:4503 find_call: = No match Their Call ID: db99328a-42ed9335@192.168.1.59 Their Tag f52b0624b20747dao1 Our tag: as7e82a748
[Sep 5 21:55:13] DEBUG[4948]: chan_sip.c:15128 sipsock_read: Invalid SIP message - rejected , no callid, len 318
[Sep 5 21:55:45] DEBUG[4948]: chan_sip.c:2079 __sip_autodestruct: Auto destroying SIP dialog ‘db99328a-42ed9335@192.168.1.59’
[Sep 5 21:55:45] DEBUG[4948]: chan_sip.c:3242 sip_destroy: Destroying SIP dialog db99328a-42ed9335@192.168.1.59
Really destroying SIP dialog ‘db99328a-42ed9335@192.168.1.59’ Method: REGISTER
Asterisk*CLI>

— (10 headers 0 lines) —
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 58c4f23c0fb95b2e4e75c0dc57d25b08@192.168.1.77 Their Tag 5e90d36cc0d69b32i1 Our tag: as6e90ef1c
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘58c4f23c0fb95b2e4e75c0dc57d25b08@192.168.1.77’ of Request 102: Match Found
Really destroying SIP dialog ‘58c4f23c0fb95b2e4e75c0dc57d25b08@192.168.1.77’ Method: OPTIONS
Asterisk*CLI>
<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6e90ef1c
Call-ID: 58c4f23c0fb95b2e4e75c0dc57d25b08@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK662d7a41
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6e90ef1c (59)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 58c4f23c0fb95b2e4e75c0dc57d25b08@192.168.1.77 (54)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK662d7a41 (57)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:15128 sipsock_read: Invalid SIP message - rejected , no callid, len 403

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6e90ef1c
Call-ID: 58c4f23c0fb95b2e4e75c0dc57d25b08@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK662d7a41
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6e90ef1c (59)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 58c4f23c0fb95b2e4e75c0dc57d25b08@192.168.1.77 (54)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK662d7a41 (57)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:57:13] DEBUG[4948]: chan_sip.c:15128 sipsock_read: Invalid SIP message - rejected , no callid, len 403
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4450 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: OPTIONS sip:100@192.168.1.59:5061 SIP/2.0 (41)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04;rport (63)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb (59)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: To: sip:100@192.168.1.59:5061 (31)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: Contact: sip:asterisk@192.168.1.77 (36)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77 (54)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: CSeq: 102 OPTIONS (17)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: User-Agent: Asterisk PBX (24)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Max-Forwards: 70 (16)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Date: Thu, 06 Sep 2007 01:58:13 GMT (35)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 11: Supported: replaces (19)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 12: Content-Length: 0 (17)
Reliably Transmitting (no NAT) to 192.168.1.59:5061:
OPTIONS sip:100@192.168.1.59:5061 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04;rport
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb
To: sip:100@192.168.1.59:5061
Contact: sip:asterisk@192.168.1.77
Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Thu, 06 Sep 2007 01:58:13 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


[Sep 5 21:58:13] DEBUG[4948]: sched.c:284 ast_sched_del: Attempted to delete nonexistent schedule entry 0!
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:2037 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #14970
Asterisk*CLI>
<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb
Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb (59)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77 (54)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04 (57)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77 Their Tag Our tag: as6b60dfeb
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:2148 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #14970
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘23cea85112ad459b2fc10b5e528e27a5@192.168.1.77’ of Request 102: Match Not Found

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb
Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb (59)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77 (54)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04 (57)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77 Their Tag 5e90d36cc0d69b32i1 Our tag: as6b60dfeb
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘23cea85112ad459b2fc10b5e528e27a5@192.168.1.77’ of Request 102: Match Found
Asterisk*CLI>
<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb
Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb (59)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77 (54)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04 (57)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77 Their Tag 5e90d36cc0d69b32i1 Our tag: as6b60dfeb
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘23cea85112ad459b2fc10b5e528e27a5@192.168.1.77’ of Request 102: Match Found
Really destroying SIP dialog ‘23cea85112ad459b2fc10b5e528e27a5@192.168.1.77’ Method: OPTIONS

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb
Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as6b60dfeb (59)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 23cea85112ad459b2fc10b5e528e27a5@192.168.1.77 (54)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK576fde04 (57)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:58:13] DEBUG[4948]: chan_sip.c:15128 sipsock_read: Invalid SIP message - rejected , no callid, len 403
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4450 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: OPTIONS sip:100@192.168.1.59:5061 SIP/2.0 (41)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK2b9eabb1;rport (63)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605 (59)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: To: sip:100@192.168.1.59:5061 (31)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: Contact: sip:asterisk@192.168.1.77 (36)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Call-ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77 (54)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: CSeq: 102 OPTIONS (17)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: User-Agent: Asterisk PBX (24)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Max-Forwards: 70 (16)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Date: Thu, 06 Sep 2007 01:59:13 GMT (35)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 11: Supported: replaces (19)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 12: Content-Length: 0 (17)
Reliably Transmitting (no NAT) to 192.168.1.59:5061:
OPTIONS sip:100@192.168.1.59:5061 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK2b9eabb1;rport
From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605
To: sip:100@192.168.1.59:5061
Contact: sip:asterisk@192.168.1.77
Call-ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Thu, 06 Sep 2007 01:59:13 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


[Sep 5 21:59:13] DEBUG[4948]: sched.c:284 ast_sched_del: Attempted to delete nonexistent schedule entry 0!
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:2037 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #14975
Asterisk*CLI>
<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605
Call-ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK2b9eabb1
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605 (59)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77 (54)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK2b9eabb1 (57)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77 Their Tag Our tag: as52c58605
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:2148 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #14975
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77’ of Request 102: Match Not Found

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605
Call-ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK2b9eabb1
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605 (59)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77 (54)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK2b9eabb1 (57)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77 Their Tag 5e90d36cc0d69b32i1 Our tag: as52c58605
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77’ of Request 102: Match Found
Asterisk*CLI>
<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605
Call-ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK2b9eabb1
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605 (59)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 3: Call-ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77 (54)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 4: CSeq: 102 OPTIONS (17)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK2b9eabb1 (57)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 6: Server: Linksys/SPA942-5.1.10 (29)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 7: Content-Length: 0 (17)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 9: Supported: replaces (19)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 10: (0)
— (10 headers 0 lines) —
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4503 find_call: = Found Their Call ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77 Their Tag 5e90d36cc0d69b32i1 Our tag: as52c58605
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:2158 __sip_ack: Stopping retransmission on ‘21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77’ of Request 102: Match Found
Really destroying SIP dialog ‘21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77’ Method: OPTIONS

<— SIP read from 192.168.1.59:5061 —>
SIP/2.0 200 OK
To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1
From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605
Call-ID: 21f8c6a4207b6dec7b08cdf8296fb3a8@192.168.1.77
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.77:5060;branch=z9hG4bK2b9eabb1
Server: Linksys/SPA942-5.1.10
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 0: SIP/2.0 200 OK (14)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 1: To: sip:100@192.168.1.59:5061;tag=5e90d36cc0d69b32i1 (54)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c:4715 parse_request: Header 2: From: “asterisk” sip:asterisk@192.168.1.77;tag=as52c58605 (59)
[Sep 5 21:59:13] DEBUG[4948]: chan_sip.c: