<--- SIP read from 192.168.1.100:5109 ---> SUBSCRIBE sip:1100@asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.1.100:5109;branch=z9hG4bKac56bb7c6f120d6c215f0cf371824380;rport From: "1100" ;tag=2255010868 To: "1100" Call-ID: 2707663927@192_168_1_100 CSeq: 918274845 SUBSCRIBE Contact: Max-Forwards: 70 User-Agent: S450 IP020970000000 Event: message-summary Expires: 3600 Allow: NOTIFY Accept: application/simple-message-summary Content-Length: 0 <--- Transmitting (no NAT) to 192.168.1.100:5109 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.100:5109;branch=z9hG4bKac56bb7c6f120d6c215f0cf371824380;rport;received=192.168.1.100 From: "1100" ;tag=2255010868 To: "1100" ;tag=as534c92bc Call-ID: 2707663927@192_168_1_100 CSeq: 918274845 SUBSCRIBE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="4013b650" Content-Length: 0 <--- SIP read from 192.168.1.100:5109 ---> line 1390 SUBSCRIBE sip:1100@asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.1.100:5109;branch=z9hG4bK3429f3c23251b17ed5f698e1c2f556ec;rport From: "1100" ;tag=2255010868 To: "1100" Call-ID: 2707663927@192_168_1_100 CSeq: 918274846 SUBSCRIBE Contact: Authorization: Digest username="1100", realm="asterisk", algorithm=MD5, uri="sip:1100@asterisk", nonce="4013b650", response="217a0c7fb8459b1f0d9723e21c472ce6" Max-Forwards: 70 User-Agent: S450 IP020970000000 Event: message-summary Expires: 3600 Allow: NOTIFY Accept: application/simple-message-summary Content-Length: 0 <-------------> [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 0: SUBSCRIBE sip:1100@asterisk SIP/2.0 (35) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.1.100:5109;branch=z9hG4bK3429f3c23251b17ed5f698e1c2f556ec;rport (88) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 2: From: "1100" ;tag=2255010868 (47) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 3: To: "1100" (30) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 4: Call-ID: 2707663927@192_168_1_100 (33) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 5: CSeq: 918274846 SUBSCRIBE (25) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 6: Contact: (38) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 7: Authorization: Digest username="1100", realm="asterisk", algorithm=MD5, uri="sip:1100@asterisk", nonce="4013b650", response="217a0c7fb8459b1f0d9723e21c472ce6" (158) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 9: User-Agent: S450 IP020970000000 (31) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 10: Event: message-summary (22) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 11: Expires: 3600 (13) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 12: Allow: NOTIFY (13) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 13: Accept: application/simple-message-summary (42) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 14: Content-Length: 0 (17) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Header 15: (0) [Jul 2 12:14:48] VERBOSE[4181] logger.c: --- (15 headers 0 lines) --- [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: = Found Their Call ID: 2707663927@192_168_1_100 Their Tag 2255010868 Our tag: as534c92bc [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Got a new subscription 2707663927@192_168_1_100 (possibly with auth) [Jul 2 12:14:48] VERBOSE[4181] logger.c: Creating new subscription [Jul 2 12:14:48] VERBOSE[4181] logger.c: Sending to 192.168.1.100 : 5109 (NAT) [Jul 2 12:14:48] VERBOSE[4181] logger.c: Found peer '1100' [Jul 2 12:14:48] VERBOSE[4181] logger.c: Looking for 1100 in from-internal (domain asterisk) [Jul 2 12:14:48] DEBUG[4181] chan_sip.c: Adding subscription for mailbox notification - peer 1100 Mailbox 1100@default [Jul 2 12:14:48] VERBOSE[4181] logger.c: Scheduling destruction of SIP dialog '2707663927@192_168_1_100' in 3610000 ms (Method: SUBSCRIBE) [Jul 2 12:14:48] VERBOSE[4181] logger.c: <--- Transmitting (no NAT) to 192.168.1.100:5109 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.100:5109;branch=z9hG4bK3429f3c23251b17ed5f698e1c2f556ec;rport;received=192.168.1.100 From: "1100" ;tag=2255010868 To: "1100" ;tag=as534c92bc Call-ID: 2707663927@192_168_1_100 CSeq: 918274846 SUBSCRIBE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 3600 Contact: ;expires=3600 Content-Length: 0 ################################################## MANUALLY ADDED DESCRIPTION ############################################################# THAT WAS THE SUBSCRIBE PART, NOW LET'S SEE THE OUTBOUND NOTIFY ... ########################################################################################################################################### --- [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Jul 2 12:14:47] DEBUG[4181] acl.c: ##### Testing 192.168.1.100 with 192.168.1.0 [Jul 2 12:14:47] VERBOSE[4181] logger.c: Scheduling destruction of SIP dialog '44a2de5123f92fc47f9ff8aa6fcd0e10@192.168.1.16' in 32000 ms (Method: NOTIFY) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 0: NOTIFY sip:1100@192.168.1.100:5109 SIP/2.0 (42) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.1.16:5060;branch=z9hG4bK7d64c85e (57) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 2: From: "Unknown" ;tag=as4ea75f10 (57) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 3: To: (33) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 4: Contact: (35) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 5: Call-ID: 44a2de5123f92fc47f9ff8aa6fcd0e10@192.168.1.16 (54) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 6: CSeq: 102 NOTIFY (16) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 9: Event: message-summary (22) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 10: Content-Type: application/simple-message-summary (48) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 11: Content-Length: 87 (18) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 12: (0) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Line: Messages-Waiting: no (20) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Line: Message-Account: sip:*97@192.168.1.16 (37) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Line: Voice-Message: 0/0 (0/0) (24) [Jul 2 12:14:47] VERBOSE[4181] logger.c: Reliably Transmitting (no NAT) to 192.168.1.100:5109: NOTIFY sip:1100@192.168.1.100:5109 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.16:5060;branch=z9hG4bK7d64c85e From: "Unknown" ;tag=as4ea75f10 To: Contact: Call-ID: 44a2de5123f92fc47f9ff8aa6fcd0e10@192.168.1.16 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 87 Messages-Waiting: no Message-Account: sip:*97@192.168.1.16 Voice-Message: 0/0 (0/0) --- <--- SIP read from 192.168.1.100:5109 ---> SIP/2.0 481 Call Leg/Transaction Does Not Exist Via: SIP/2.0/UDP 192.168.1.16:5060;branch=z9hG4bK7d64c85e From: "Unknown" ;tag=as4ea75f10 To: Call-ID: 44a2de5123f92fc47f9ff8aa6fcd0e10@192.168.1.16 CSeq: 102 NOTIFY Content-Length: 0 <-------------> [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 0: SIP/2.0 481 Call Leg/Transaction Does Not Exist (47) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.1.16:5060;branch=z9hG4bK7d64c85e (57) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 2: From: "Unknown" ;tag=as4ea75f10 (57) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 3: To: (33) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 4: Call-ID: 44a2de5123f92fc47f9ff8aa6fcd0e10@192.168.1.16 (54) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 5: CSeq: 102 NOTIFY (16) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 6: Content-Length: 0 (17) [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Header 7: (0) [Jul 2 12:14:47] VERBOSE[4181] logger.c: --- (7 headers 0 lines) --- [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: = Found Their Call ID: 44a2de5123f92fc47f9ff8aa6fcd0e10@192.168.1.16 Their Tag Our tag: as4ea75f10 [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #177 [Jul 2 12:14:47] DEBUG[4181] chan_sip.c: Stopping retransmission on '44a2de5123f92fc47f9ff8aa6fcd0e10@192.168.1.16' of Request 102: Match Found [Jul 2 12:14:47] WARNING[4181] chan_sip.c: Remote host can't match request NOTIFY to call '44a2de5123f92fc47f9ff8aa6fcd0e10@192.168.1.16'. Giving up. ############################################## MANUALLY ADDED DESCRIPTION ################################################## UHH, the Notify is using CALL-ID: 44a2de5123f92fc47f9ff8aa6fcd0e10@192.168.1.16 of which we have no SUBSCRIBE in this trace But a new Subscribe as occured using CALL-ID: 2707663927@192_168_1_100, why isn't that subscription used and what's causing the domain name to change. I see the domainparts "@192.168.1.16" and "@192_168_1_100"? Are two peers interfering with each other??