[Home]

Summary:ASTERISK-06665: Asterisk does not process 'message-summary' subscriptions.
Reporter:caspy (caspy)Labels:
Date Opened:2006-03-30 11:27:02.000-0600Date Closed:2006-04-03 15:26:39
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/Subscriptions
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:Asterisk do not process 'message-summary' SUBSCRIBE requests, thus not keep "Call-ID", "tag", and "Event" headers of SUBSCRIBE.
This headers are needed for NOTIFY requests (message-summary), which Asterisk send to this (just subscribed) client.

Without this, some phones (Avaya 4602, 4610, for example) do not accept NOTIFY, cause they cann't match received NOTIFY with their SUBSCRIBE.

From RFC3265, 3.3.4:
  NOTIFY requests are matched to such SUBSCRIBE requests if they
  contain the same "Call-ID", a "To" header "tag" parameter which
  matches the "From" header "tag" parameter of the SUBSCRIBE, and the
  same "Event" header field.

****** ADDITIONAL INFORMATION ******

in logs it looks like:

=====
Reliably Transmitting (NAT) to 10.xx.xx.253:5060:
NOTIFY sip:xxxx@10.xx.xx.253:5060 SIP/2.0
Via: SIP/2.0/UDP 10.xx.xx.2:5060;branch=z9hG4bK06f2294e;rport
From: "asterisk" <sip:asterisk@10.xx.xx.2>;tag=as771650cd
To: <sip:xxxx@10.xx.xx.253:5060>
Contact: <sip:asterisk@10.xx.xx.2>
Call-ID: 4d6579134345e8622ab6e7d915fbe16f@10.xx.xx.2
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Subscription-State: active
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 85

Messages-Waiting: yes
Message-Account: sip:123@10.xx.xx.2
Voice-Message: 2/0 (0/0)

---
<-- SIP read from 10.xx.xx.253:5060:
SIP/2.0 481 Call Does Not Exist
Call-ID: 4d6579134345e8622ab6e7d915fbe16f@10.xx.xx.2
CSeq: 102 NOTIFY
From: "asterisk" <sip:asterisk@10.xx.xx.2>;tag=as771650cd
To: <sip:xxxx@10.xx.xx.253:5060>;tag=59c2bd0b733f060
Via: SIP/2.0/UDP 10.xx.xx.2:5060;branch=z9hG4bK06f2294e;rport
Content-Length: 0
User-Agent: Avaya SIP R2.2 Endpoint Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26


--- (8 headers 0 lines)---
=====


Additionally, when Avaya send SUBSCRIBE request for message-summary, it does not set 'Accept' header. But this issue can be easily 'dirty hacked' by making comparation in handle_request_subscribe() in such way:
(!strcmp(event, "message-summary") && (!strcmp(accept, "application/simple-message-summary") || strstr(p->useragent, "Avaya")))


If any help or debug needed, i can provide any additional information.
Comments:By: Olle Johansson (oej) 2006-03-30 12:01:55.000-0600

Please provide a full SIP debug of the subscribe and the notifications using the latest svn trunk. Thanks.
By: caspy (caspy) 2006-03-31 06:01:45.000-0600

<-- SIP read from 10.15.5.255:5060:
SUBSCRIBE sip:1001@masterhost.ru SIP/2.0
Via: SIP/2.0/UDP 10.15.5.255:5060;branch=z9hG4bK5674bc905
Max-Forwards: 70
Content-Length: 0
To: 1001 <sip:1001@masterhost.ru>
From: 1001 <sip:1001@masterhost.ru>;tag=5524d12eee791fe
Call-ID: 2002e9e21ab9f71814cdde0ab258432a@10.15.5.255
CSeq: 136497988 SUBSCRIBE
Route: <sip:10.15.1.2;lr>
Supported: timer
Expires: 86400
Event: message-summary
Contact: 1001 <sip:1001@10.15.5.255:5060>
Supported: replaces
User-Agent: Avaya SIP R2.2 Endpoint Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26


--- (15 headers 0 lines)---
Using latest SUBSCRIBE request as basis request
Sending to 10.15.5.255 : 5060 (NAT)
Found peer '1001'
Transmitting (NAT) to 10.15.5.255:5060:
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.15.5.255:5060;branch=z9hG4bK5674bc905;received=10.15.5.255
From: 1001 <sip:1001@masterhost.ru>;tag=5524d12eee791fe
To: 1001 <sip:1001@masterhost.ru>;tag=as14975764
Call-ID: 2002e9e21ab9f71814cdde0ab258432a@10.15.5.255
CSeq: 136497988 SUBSCRIBE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1001@10.15.1.2>
WWW-Authenticate: Digest realm="xxx.masterhost.ru", nonce="yyy"
Content-Length: 0


---
Scheduling destruction of call '2002e9e21ab9f71814cdde0ab258432a@10.15.5.255' in 15000 ms
<-- SIP read from 10.15.5.255:5060:
SUBSCRIBE sip:1001@masterhost.ru SIP/2.0
Via: SIP/2.0/UDP 10.15.5.255:5060;branch=z9hG4bK3d257a39f
Max-Forwards: 70
Content-Length: 0
To: 1001 <sip:1001@masterhost.ru>
From: 1001 <sip:1001@masterhost.ru>;tag=5524d12eee791fe
Call-ID: 2002e9e21ab9f71814cdde0ab258432a@10.15.5.255
CSeq: 136497989 SUBSCRIBE
Route: <sip:10.15.1.2;lr>
Supported: timer
Expires: 86400
Event: message-summary
Contact: 1001 <sip:1001@10.15.5.255:5060>
Supported: replaces
Authorization:Digest response="zzz",username="1001",realm="xxx.masterhost.ru",nonce="yyy",uri="sip:1001@masterhost.ru"
User-Agent: Avaya SIP R2.2 Endpoint Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26


--- (16 headers 0 lines)---
Found peer '1001'
Looking for 1001 in fromoffice (domain masterhost.ru)
Transmitting (NAT) to 10.15.5.255:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.15.5.255:5060;branch=z9hG4bK3d257a39f;received=10.15.5.255
From: 1001 <sip:1001@masterhost.ru>;tag=5524d12eee791fe
To: 1001 <sip:1001@masterhost.ru>;tag=as14975764
Call-ID: 2002e9e21ab9f71814cdde0ab258432a@10.15.5.255
CSeq: 136497989 SUBSCRIBE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Expires: 3600
Content-Length: 0


---
Destroying call '2002e9e21ab9f71814cdde0ab258432a@10.15.5.255'
13 headers, 3 lines
Reliably Transmitting (NAT) to 10.15.5.255:5060:
NOTIFY sip:1001@10.15.5.255:5060 SIP/2.0
Via: SIP/2.0/UDP 10.15.1.2:5060;branch=z9hG4bK70e10dc9;rport
From: "asterisk" <sip:asterisk@10.15.1.2>;tag=as486df860
To: <sip:1001@10.15.5.255:5060>
Contact: <sip:asterisk@10.15.1.2>
Call-ID: 4044405e756a33ef33d13ed246b65980@10.15.1.2
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Subscription-State: active
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 85

Messages-Waiting: yes
Message-Account: sip:123@10.15.1.2
Voice-Message: 1/0 (0/0)

---
Scheduling destruction of call '4044405e756a33ef33d13ed246b65980@10.15.1.2' in 15000 ms
phone2*CLI>
<-- SIP read from 10.15.5.255:5060:
SIP/2.0 481 Call Does Not Exist
Call-ID: 4044405e756a33ef33d13ed246b65980@10.15.1.2
CSeq: 102 NOTIFY
From: "asterisk" <sip:asterisk@10.15.1.2>;tag=as486df860
To: <sip:1001@10.15.5.255:5060>;tag=c2f444288b008f9
Via: SIP/2.0/UDP 10.15.1.2:5060;branch=z9hG4bK70e10dc9;rport
Content-Length: 0
User-Agent: Avaya SIP R2.2 Endpoint Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26


--- (8 headers 0 lines)---
   -- Got SIP response 481 "Call Does Not Exist" back from 10.15.5.255
Destroying call '4044405e756a33ef33d13ed246b65980@10.15.1.2'



According to this trace, Avaya subscribed with:
Call-ID: 2002e9e21ab9f71814cdde0ab258432a, and
tag=5524d12eee791fe.
After this, it is waiting NOTIFY with this Call-ID and tag, but receives:
Call-ID: 4044405e756a33ef33d13ed246b65980, and
tag=as486df860



Please, mention, that chan_sip.c slightly patched:
in handle_request_subscribe():
(!strcmp(event, "message-summary") && !strcmp(accept, "application/simple-message-summary"))
replaced by:
(!strcmp(event, "message-summary") && (!strcmp(accept, "application/simple-message-summary") || strstr(p->useragent, "Avaya")))
in two places. It's needed for Avaya to subscribe for message-summary.

And in NOTIFY request added header "Subscription-State: active".
It is also needed for Avaya? to begin parsing of NOTIFY request.
By: Olle Johansson (oej) 2006-03-31 17:27:12.000-0600

Please test with latest svn trunk, we added support for MWI subscriptions a few days ago.
By: caspy (caspy) 2006-04-03 03:32:53

For Avaya's MWI SUBSCRIBE to work, it is still needed to replace:
(!strcmp(event, "message-summary") && !strcmp(accept, "application/simple-message-summary"))
by:
(!strcmp(event, "message-summary") && (!strcmp(accept, "application/simple-message-summary") || strstr(p->useragent, "Avaya")))

After this, we get such trace:

<-- SIP read from 10.15.4.254:5060:
SUBSCRIBE sip:1001@masterhost.ru SIP/2.0
Via: SIP/2.0/UDP 10.15.4.254:5060;branch=z9hG4bK3e481a48b
Max-Forwards: 70
Content-Length: 0
To: 1001 <sip:1001@masterhost.ru>
From: 1001 <sip:1001@masterhost.ru>;tag=46d2bce065686bf
Call-ID: ef41c7cf95e8cabad708711136dfecc7@10.15.4.254
CSeq: 1745971486 SUBSCRIBE
Route: <sip:10.15.1.3;lr>
Supported: timer
Expires: 86400
Event: message-summary
Contact: 1001 <sip:1001@10.15.4.254:5060>
Supported: replaces
Authorization:Digest response="xxx",username="1001",realm="yyy.masterhost.ru",nonce="zzz",uri="sip:1001@masterhost.ru"
User-Agent: Avaya SIP R2.2 Endpoint Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26


--- (16 headers 0 lines)---
Found peer '1001'
Looking for 1001 in fromoffice (domain masterhost.ru)
Scheduling destruction of SIP dialog 'ef41c7cf95e8cabad708711136dfecc7@10.15.4.254' in 3610000 ms (Method: SUBSCRIBE)
Transmitting (NAT) to 10.15.4.254:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.15.4.254:5060;branch=z9hG4bK3e481a48b;received=10.15.4.254
From: 1001 <sip:1001@masterhost.ru>;tag=46d2bce065686bf
To: 1001 <sip:1001@masterhost.ru>;tag=as55d92c6c
Call-ID: ef41c7cf95e8cabad708711136dfecc7@10.15.4.254
CSeq: 1745971486 SUBSCRIBE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Expires: 3600
Contact: <sip:1001@10.15.1.3>;expires=3600
Content-Length: 0


---
Reliably Transmitting (NAT) to 10.15.4.254:5060:
NOTIFY sip:1001@10.15.4.254:5060 SIP/2.0
Via: SIP/2.0/UDP 10.15.1.3:5060;branch=z9hG4bK6e3023f2;rport
From: "asterisk" <sip:asterisk@masterhost.ru>;tag=as55d92c6c
To: <sip:1001@10.15.4.254:5060>
Contact: <sip:asterisk@10.15.1.3>
Call-ID: ef41c7cf95e8cabad708711136dfecc7@10.15.4.254
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 94

Messages-Waiting: yes
Message-Account: sip:asterisk@masterhost.ru
Voice-Message: 3/3 (0/0)

---

<-- SIP read from 10.15.4.254:5060:
SIP/2.0 481 Call Does Not Exist
Call-ID: ef41c7cf95e8cabad708711136dfecc7@10.15.4.254
CSeq: 102 NOTIFY
From: "asterisk" <sip:asterisk@masterhost.ru>;tag=as55d92c6c
To: <sip:1001@10.15.4.254:5060>;tag=592c78cbd1fcf35
Via: SIP/2.0/UDP 10.15.1.3:5060;branch=z9hG4bK6e3023f2;rport
Content-Length: 0
User-Agent: Avaya SIP R2.2 Endpoint Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26


--- (8 headers 0 lines)---



It seems, that Avaya strictly support RFC: it doesn't like unknown "tag" field.

Thanks.
By: Olle Johansson (oej) 2006-04-03 04:42:28

I am really hesitant to add vendor-specific patches. What does Avaya say about the missing Accept header?
By: caspy (caspy) 2006-04-03 04:56:56

Avaya says nothing.
Avaya does not include it in SUBSCRIBE request, thus Asterisk do not treat it as a message-summary subscribe request.

And what about saving 'tag' field?
By: Olle Johansson (oej) 2006-04-03 05:06:00

Internal note from RFC 3842: A future extension MAY define other NOTIFY bodies.  If no "Accept"
  header is present in the SUBSCRIBE, the body type defined in this
  document MUST be assumed.

Meaning we can assume Accept: application/simple-message-summary if no accept header is present.
By: caspy (caspy) 2006-04-03 05:11:19

Yes,
but this one if():
(!strcmp(event, "message-summary") && !strcmp(accept, "application/simple-message-summary"))
assume, that 'Accept: application/simple-message-summary' must be in subscribe request
By: Olle Johansson (oej) 2006-04-03 05:51:21

Fixed in svn trunk, revision 17050
By: Olle Johansson (oej) 2006-04-03 05:52:16

Asterisk now accepts MWI subscriptions with no Accept header, defaulting to the default message format. If other format is requested, we will send 405 error since we only support one MWI format.
By: caspy (caspy) 2006-04-03 06:25:53

This is not the primary topic of bug.
Avaya's SIP phones still do not accept MWI NOTIFY request, saying:
SIP/2.0 481 Call Does Not Exist
(see my last trace from svn trunk)

It seems, that this is because NOTIFY request come with 'tag' field in "From:" header different to one, that was given by phone in SUBSCRIBE request.
By: Olle Johansson (oej) 2006-04-03 07:00:24

Yes, the to tag is missing in the notify
By: Olle Johansson (oej) 2006-04-03 15:26:11

Ok, fix committed to svn 1.2 rev 17147 and svn trunk. Please test!