[Home]

Summary:ASTERISK-08339: [patch] MWI Error with NOTIFY on Cisco IP phone firmware > 8.0.3
Reporter:Matt Gibson (flewid)Labels:
Date Opened:2006-12-12 16:41:26.000-0600Date Closed:2006-12-29 05:04:35.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/Interoperability
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) ast14_b4_patch.txt
( 1) ast14_ciscomwipatch.txt
Description:When Using Cisco 7970 with Asterisk 1.4 (Firmware 8.0.3, 8.0.4, 8.2) the MWI indicator does not function. It used to work with Firmware 8.0.2, which leads me to believe Cisco has changed something, or Asterisk may have a bug. There have been discussions on this on the mailing list, but I have not found an actual bug open on Mantis.

Running Ast 1.4B3, on Gentoo, with a cisco 2950 switch in between. Any help would be greatly appreciated, and if I misssed supplying any information please let me know and I will get that in ASAP.

Here is what Asterisk reports with "SIP DEBUG" when MWI is trying to be sent:

<--- SIP read from 10.0.1.37:49231 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.1.24:5060;branch=z9hG4bK69d07069;rport
From: <sip:8080@10.0.1.24>;tag=as3d369d89
To: "Matt Gibson" <sip:8080@10.0.1.24>;tag=0015faa0e8cf0131dee3613e-b4b25ba2
Call-ID: 0015faa0-e8cf000c-b59da28e-eadada32@10.0.1.37
Date: Tue, 12 Dec 2006  GMT
CSeq: 102 BYE
Server: Cisco-CP7970G/8.0
Content-Length: 0


<------------->
--- (9 headers 0 lines) ---
SIP Response message for INCOMING dialog BYE arrived
Really destroying SIP dialog '0015faa0-e8cf000c-b59da28e-eadada32@10.0.1.37' Method: ACK
Scheduling destruction of SIP dialog '7855479d7ce146624e067ce1461cb9b9@10.0.1.24' in 32000 ms (Method: NOTIFY)
Reliably Transmitting (no NAT) to 10.0.1.37:5060:
NOTIFY sip:8080@10.0.1.37:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.0.1.24:5060;branch=z9hG4bK39c5e047;rport
From: "asterisk" <sip:asterisk@10.0.1.24>;tag=as25b47f6e
To: <sip:8080@10.0.1.37:5060;transport=udp>
Contact: <sip:asterisk@10.0.1.24>
Call-ID: 7855479d7ce146624e067ce1461cb9b9@10.0.1.24
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 90

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

---
pbx*CLI>
<--- SIP read from 10.0.1.37:49232 --->
SIP/2.0 400 Bad Request
Via: SIP/2.0/UDP 10.0.1.24:5060;branch=z9hG4bK39c5e047;rport
From: "asterisk" <sip:asterisk@10.0.1.24>;tag=as25b47f6e
To: <sip:8080@10.0.1.37:5060;transport=udp>
Call-ID: 7855479d7ce146624e067ce1461cb9b9@10.0.1.24
Date: Tue, 12 Dec 2006  GMT
Warning: 399 Bad MWI NOTIFY
CSeq: 102 NOTIFY
Content-Length: 0

Comments:By: Matt Gibson (flewid) 2006-12-12 22:58:05.000-0600

Screwed around with the cisco a bit tonight and got it to spew me some debug statements on the command line interface...

DBG 22:50:18.645881 JVM: cprGetBuffer: Enter
DBG 22:50:18.646765 JVM:
cprGetBuffer - will use heap. Region - SIP  BufferSize - 4096
DBG 22:50:18.647649 JVM: cpr_cnu_sbrk: added 4096 bytes of memory
DBG 22:50:18.648798 JVM: sip_platform_udp_channel_read: rcvd on fd[23]
DBG 22:50:18.650399 JVM: cprReleaseBuffer: Enter
DBG 22:50:18.651215 JVM:
cprReleaseBuffer - Buffer was from heap not pool.
DBG 22:50:18.652101 JVM: SIPProcessUDPMessage: recv UDP message from <10.0.1.24>:<5060>, length=<554>, message=
DBG 22:50:18.652981 JVM: NOTIFY sip:8080@10.0.1.37:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.0.1.24:5060;branch=z9hG4bK62c3e628;rport
From: "asterisk" <sip:asterisk@10.0.1.24>;tag=as12786ddb
To: <sip:8080@10.0.1.37:5060;transport=udp>
Contact: <sip:asterisk@10.0.1.24>
Call-ID: 6cc026b778c714f92e22a28b4cd5f949@10.0.1.24
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 89

Messages-Waiting: no
Message-Account: sip:asterisk@10.0.1.24
Voice-Message: 0/0 (0/0)
DBG 22:50:18.656288 JVM: SIPTaskProcessSIPMessage: Received SIP message NOTIFY.
DBG 22:50:18.657539 JVM: CFGID 17: get str: line1_name = 8080
DBG 22:50:18.658406 JVM: CFGID 9: Get Val: line1_featureID = 9
DBG 22:50:18.659291 JVM: CFGID 17: get str: line1_name = 8080
DBG 22:50:18.660362 JVM: CFGID 49: get str: line1_contact = 8080
DBG 22:50:18.661475 JVM: SIPTaskProcessSIPNotify: NOTIFY: mwi
ERR 22:50:18.662408 JVM: SIPTaskProcessSIPNotify: Error: Bad MWI NOTIFY!
DBG 22:50:18.663585 JVM: sipSPISendErrorResponse: Sending response 400...
DBG 22:50:18.665749 JVM: sipRelDevCoupledMessageStore: Storing for reTx (cseq=102, method=NOTIFY, to_tag=<>)
DBG 22:50:18.667234 JVM: CFGID 195: Get Val: natEnabled = 0
DBG 22:50:18.668487 JVM: CFGID 207: Get Val: dscpForCm2Dvce = 96
DBG 22:50:18.669494 JVM: sipTransportSendMessage: Opened a one-time UDP send channel to server <10.0.1.24>:<5060>, handle = 32 local port= 0
DBG 22:50:18.670940 JVM: sipTransportSendMessage:Sent SIP message to <10.0.1.24>:<5060>, handle=<32>, length=<340>, message=
DBG 22:50:18.671814 JVM: SIP/2.0 400 Bad Request
Via: SIP/2.0/UDP 10.0.1.24:5060;branch=z9hG4bK62c3e628;rport
From: "asterisk" <sip:asterisk@10.0.1.24>;tag=as12786ddb
To: <sip:8080@10.0.1.37:5060;transport=udp>
Call-ID: 6cc026b778c714f92e22a28b4cd5f949@10.0.1.24
Date: Wed, 13 Dec 2006  GMT
Warning: 399 Bad MWI NOTIFY
CSeq: 102 NOTIFY
Content-Length: 0

DBG 22:50:18.673006 JVM: sipTransportSendMessage: Closed a one-time UDP send channel handle = 32
NOT 22:50:19.939593 NTP: Local clock sync'd to NTP reference
By: Serge Vecher (serge-v) 2006-12-13 08:34:14.000-0600

that notify looks fine; I think you should contact Cisco, since obviously they've borked something in firmware.
By: Matt Gibson (flewid) 2006-12-13 15:40:33.000-0600

darn. I was hoping you wouldn't say that. I will try emailing cisco, but don't expect a response from them.

Is there any way we can add like "mwitype=cisco" or something to asterisk? or is that too hacky to fix this? I just say this because cisco probably will not help us asterisk users.
By: Yung (betatester) 2006-12-13 20:09:40.000-0600

I am running * 1.2.13 and Cisco 7941.  Didn't have issue with MWI with firmware 8.0.2 but it broke since 8.0.3 and I just tried the newest released firmware 8.2.1 from Cisco.  MWI still not working with the latest released firmware.  I am not sure who's bug is this but I am pretty sure that Cisco won't do anything just because it doesn't work with Asterisk.  I remember reading from somewhere that Cisco do not like the "tag" on the from heading.

From: "asterisk" <sip:asterisk@10.0.1.24>;tag=as25b47f6e

My question is how to disable the tag if possible in the source code without a lot of work so I can test this.
By: Joshua C. Colp (jcolp) 2006-12-13 21:45:15.000-0600

I'll chime in here... does anyone have a NOTIFY packet that *DOES* work with the new Cisco firmware?
By: Yung (betatester) 2006-12-14 00:35:50.000-0600

Ok, I have been playing with sipsak and trying to figure out what can the correct NOTIFY message should be for cisco 8.0.3 to 8.2.1.  Here is what I found out.  notice at the "voice-message:"

MWI message with sip 8-2-1 Notify message that works
-------------------------------------------------------
NOTIFY sip:103@192.168.0.57:5060;transport=udp SIP/2.0
From: "Unknown" <sip:Unknown@192.168.0.5>;tag=as78f97f54
To: <sip:103@192.168.0.57:5060;transport=udp>
Contact: <sip:Unknown@192.168.0.5>
Call-ID: 5ef374d630942e2f0ac5e9121ccefb76@192.168.0.5
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary

Messages-Waiting: yes
Message-Account: sip:asterisk@192.168.0.5
Voice-Message: 1/0


None working MWI message with sip 8-2-1
-------------------------------------------
NOTIFY sip:103@192.168.0.57:5060;transport=udp SIP/2.0
From: "Unknown" <sip:Unknown@192.168.0.5>;tag=as78f97f54
To: <sip:103@192.168.0.57:5060;transport=udp>
Contact: <sip:Unknown@192.168.0.5>
Call-ID: 5ef374d630942e2f0ac5e9121ccefb76@192.168.0.5
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 92

Messages-Waiting: yes
Message-Account: sip:asterisk@192.168.0.5
Voice-Message: 1/0 (0/0)


By: Matt Gibson (flewid) 2006-12-14 00:41:03.000-0600

Beat me to it :)

Also notice that the working one seems to be sending the "Content-Length: 92" whereas that line is not displayed on the non working version. Could that play a factor as well as the "(0/0)" being there?
By: Yung (betatester) 2006-12-14 09:26:11.000-0600

The content-Length can be there.  I just tested it with and without out, both works.  The key element is "Voice-Message:"  Here is another working example with "Content-Length".  This also works with X-Lite, I guess the fix is not to have (0/0).  Do you know what (0/0) is for? old messages?

NOTIFY sip:103@192.168.0.57:5060;transport=udp SIP/2.0
From: "Unknown" <sip:Unknown@192.168.0.5>;tag=as78f97f54
To: <sip:103@192.168.0.57:5060;transport=udp>
Contact: <sip:Unknown@192.168.0.5>
Call-ID: 5ef374d630942e2f0ac5e9121ccefb76@192.168.0.5
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 92

Messages-Waiting: yes
Message-Account: sip:asterisk@192.168.0.5
Voice-Message: 1/0
By: Joshua C. Colp (jcolp) 2006-12-14 09:31:43.000-0600

Voice-Message: 1/0 (0/0)

means:

1 new message, 0 old messages with 0 urgent new messages and 0 urgent old messages.

ie:

(0/0) = 0 urgent new messages/0 urgent old messages

It's perfectly valid to have that there per RFC 3842.
By: Yung (betatester) 2006-12-14 15:51:56.000-0600

Correct me if I am wrong.  According to RFC3842, the urgent messages is optional.   Yes, I have to say Cisco didn't follow the standard.  I looked at chan_sip.c and realized that (0/0) is hard coded.  Since this is optional and it is hard coded then I don't see any reason it need to be there (astersik is not using it anyway).  In line 5290 (based on 1.2.13).  I took the (0/0) off and recompiled and MWI is working now.  

static int transmit_notify_with_mwi(struct sip_pvt *p, int newmsgs, int oldmsgs, char *vmexten)
{
       struct sip_request req;
       char tmp[500];
       char *t = tmp;
       size_t maxbytes = sizeof(tmp);
       char iabuf[INET_ADDRSTRLEN];

       initreqprep(&req, p, SIP_NOTIFY);
       add_header(&req, "Event", "message-summary");
       add_header(&req, "Content-Type", default_notifymime);

       ast_build_string(&t, &maxbytes, "Messages-Waiting: %s\r\n", newmsgs ? "yes" : "no");
       ast_build_string(&t, &maxbytes, "Message-Account: sip:%s@%s\r\n", !ast_strlen_zero(vmexten) ? vmexten : global_vmexten, ast_strlen_zero(p->fromdomain) ? ast_inet_ntoa(iabuf, sizeof(iabuf), p->ourip) : p->fromdomain);
       ast_build_string(&t, &maxbytes, "Voice-Message: %d/%d (0/0)\r\n", newmsgs, oldmsgs);

       if (t > tmp + sizeof(tmp))
               ast_log(LOG_WARNING, "Buffer overflow detected!!  (Please file a bug report)\n");

       add_header_contentLength(&req, strlen(tmp));
       add_line(&req, tmp);

       if (!p->initreq.headers) { /* Use this as the basis */
               copy_request(&p->initreq, &req);
               parse_request(&p->initreq);
               if (sip_debug_test_pvt(p))
                       ast_verbose("%d headers, %d lines\n", p->initreq.headers, p->initreq.lines);
               determine_firstline_parts(&p->initreq);
       }

       return send_request(p, &req, 1, p->ocseq);
}


By: Matt Gibson (flewid) 2006-12-14 16:39:10.000-0600

Confirmed the above fix works on the 7970 with Asterisk 1.4 as well!

Awesome.

So, how can we make this proper I wonder? Maybe a
"sendvmextras=yes/no" for the peer configuration?

Also noticed that MWI will not work if mailbox=<ext>@<vmcontext> isn't in the sip.conf.
By: Serge Vecher (serge-v) 2006-12-14 16:43:33.000-0600

can we please have the change in the form of a patch file, with a confirmation of the disclaimer status?
By: Matt Gibson (flewid) 2006-12-14 16:59:47.000-0600

Attached a patch for asterisk 1.4 - I have already submitted a disclaimer for previous bugs do I need to submit another one?
By: Olle Johansson (oej) 2006-12-15 05:10:44.000-0600

Well, this is kind of hard. Cisco should NOT send bad request for something that is ok according to the RFC. That's indeed a bug.

Removing it doesn't help. It's there for a reason, propably for other devices that has a bug and requests it.

The only way forward, if we believe that Cisco won't fix a bad bug, is to only remove it if a special option is enabled. "BuggyCISCOmwi". It's against our policys to do that, really, but it has been done in some cases (look at polycom fixes.)
By: Matt Gibson (flewid) 2006-12-17 04:13:39.000-0600

Added a new patch for the latest beta release.

oej, I agree it's not the most elegant solution, but as you say, look at the polycoms :)
By: Olle Johansson (oej) 2006-12-27 10:50:20.000-0600

Added option "buggyciscomwi" to 1.4 in svn, rev 48982 and svn trunk. Please test and confirm if it works for you.
By: Serge Vecher (serge-v) 2006-12-27 15:24:24.000-0600

oej: would it be a good idea to add a bug # reference in the added sip.conf.sample entries to avoid searching the bug-tracker in the future for affected firmware versions?