This is a patch for a problem I described back in April, but didn't see any
response. My previous messages describing the problem are below (including
packet trace and analysis), after the patch.
I'm not sure the solution is the right one, but it does fix the problem I was
observing (MWI notifications not calling pjsua's on_mwi_info, due to problems
low in the sip stack).
The patch is for 1.8.5, but applies cleanly to 1.10.
Patch:
Index: pjproject-1.8.5/pjsip/src/pjsip/sip_transaction.c
===================================================================
--- pjproject-1.8.5/pjsip/src/pjsip/sip_transaction.c (revision 32446)
+++ pjproject-1.8.5/pjsip/src/pjsip/sip_transaction.c (revision 32607)
@@ -360,14 +360,15 @@
pj_str_t *key,
pjsip_role_e role,
const pjsip_method *method,
- const pj_str_t *branch)
+ const pj_str_t *branch,
+ int cseq)
{
char *p;
PJ_ASSERT_RETURN(pool && key && method && branch, PJ_EINVAL);
p = key->ptr = (char*)
- pj_pool_alloc(pool, branch->slen + method->name.slen + 4 );
+ pj_pool_alloc(pool, branch->slen + method->name.slen + 4 + 25 );
/* Add role. */
*p++ = (char)(role==PJSIP_ROLE_UAC ? 'c' : 's');
@@ -384,6 +385,11 @@
pj_memcpy(p, branch->ptr, branch->slen);
p += branch->slen;
+ if (0==pj_strcmp2(&method->name, "NOTIFY")) {
+ *p = '-' ;
+ p += pj_utoa((pj_uint32_t)cseq, p) ;
+ }
+
/* Set length */
key->slen = p - key->ptr;
@@ -412,8 +418,9 @@
if (pj_strncmp(branch,&rfc3261_branch,PJSIP_RFC3261_BRANCH_LEN)==0) {
+ int cseq = rdata->msg_info.cseq->cseq ;
/* Create transaction key. */
- return create_tsx_key_3261(pool, key, role, method, branch);
+ return create_tsx_key_3261(pool, key, role, method, branch, cseq);
} else {
/* Create the key for the message. This key will be matched up
@@ -1277,7 +1284,7 @@
/* Generate transaction key. */
create_tsx_key_3261( tsx->pool, &tsx->transaction_key,
PJSIP_ROLE_UAC, &tsx->method,
- &via->branch_param);
+ &via->branch_param, cseq->cseq);
/* Calculate hashed key value. */
#ifdef PRECALC_HASH
________________________________
From: Matt DiMeo <mattdimeo@xxxxxxxxx>
To: pjsip at lists.pjsip.org
Sent: Thu, April 7, 2011 1:22:44 PM
Subject: Re: pjsua mwi problems: cseq ack problem
Regarding my previous message about problems with incorrect CSeq on responses to
mwi notify....
I think I've figured out what's going on, but could use advice on how to fix it.
What seems to be happening is that mod-tsx-layer is deciding that the incoming
notifies are just retransmittals of the previous CSeq, and just resending the
200 response to the previous notify.
This happens because the branch tag in the via header is the same across
mulitple NOTIFY messages from the same SUBSCRIBE, so that when mod-tsx-layer
calls pjsip_tsx_create_key, it comes up with the same value as the previous
transaction.
mod-tsx-layer then consumes the message, so the message never makes it to
mod-evsub.
My plan to solve my problem is to change create_tsx_key_3261() such that, when
the method is NOTIFY, it will include the CSeq id as part of the key string
created. I'm not at all sure that that is correct behavior, however.
Any opinions on this solution?
Thanks in advance,
-m@
________________________________
From: Matt DiMeo <mattdimeo@xxxxxxxxx>
To: pjsip at lists.pjsip.org
Sent: Wed, April 6, 2011 1:58:35 PM
Subject: pjsua mwi problems: cseq ack problem
I'm seeing multiple problems with pjsua MWI handling. I've looked into where to
fix it, but got lost in the layers of code and could use suggestions on where to
focus my debugging.
I've seen this in both 1.8.5 and 1.8.10
Problem 1: apparently incorrect cseq on ACK of mwi notify
In this problem, the mwi subscription will sometimes get into a state where it
will send ACKs with an incorrect cseq value, generally a cseq from the previous
MWI notify.
This state continues (with broken MWI) until some other sip transaction occurs
(such as a reregistration), which seem to clear the error state.
In the following pjsip output, you'll see
1. notify with cseq 105 (notification of 2/4 new/old voice message) from
asterisk (10.10.3.77)
2. correct 200 OK response with cseq 105 from pjsip (10.10.3.150)
3. notify with cseq 106 (1/5 new/old messages)
4. INCORRECT 200 OK response with cseq 105 (should be 106)
5. asterisk retries notify with cseq 106
6. INCORRECT 200 OK response with cseq 105
7.... asterisk retries about six more times, and keeps getting incorrect
responses.
8. Asterisk eventually gives up retrying. We never get an on_mwi_info response.
Any suggestions would be very welcome.
13:44:48.229 pjsua_core.c RX 607 bytes Request msg NOTIFY/cseq=105
(rdata0x7f2064000908) from UDP 10.10.3.77:5060:
NOTIFY sip:321 at 10.10.3.150:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.3.77:5060;branch=z9hG4bK259bf4a5;rport
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150:5060>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
Contact: <sip:unknown at 10.10.3.77>
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
CSeq: 105 NOTIFY
User-Agent: Asterisk PBX (digium)
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 92
Messages-Waiting: yes
Message-Account: sip:voicemail at 10.10.3.77
Voice-Message: 2/4 (0/0)
--end msg--
13:44:48.230 pjsua_core.c TX 497 bytes Response msg 200/NOTIFY/cseq=105
(tdta0x7f20640048b0) to UDP 10.10.3.77:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP
10.10.3.77:5060;rport=5060;received=10.10.3.77;branch=z9hG4bK259bf4a5
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
CSeq: 105 NOTIFY
Contact: <sip:321 at 10.10.3.150:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Content-Length: 0
--end msg--
13:44:48.230 evsub0x7f20640 Subscription state changed ACTIVE --> ACTIVE
13:44:48.230 pjsua_pres.c MWI subscription for sip:321 at 10.10.3.77 is ACTIVE
13:44:58.233 pjsua_core.c RX 607 bytes Request msg NOTIFY/cseq=106
(rdata0x7f2064000908) from UDP 10.10.3.77:5060:
NOTIFY sip:321 at 10.10.3.150:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.3.77:5060;branch=z9hG4bK259bf4a5;rport
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150:5060>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
Contact: <sip:unknown at 10.10.3.77>
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
CSeq: 106 NOTIFY
User-Agent: Asterisk PBX (digium)
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 92
Messages-Waiting: yes
Message-Account: sip:voicemail at 10.10.3.77
Voice-Message: 1/5 (0/0)
--end msg--
13:44:58.233 pjsua_core.c TX 497 bytes Response msg 200/NOTIFY/cseq=105
(tdta0x7f20640048b0) to UDP 10.10.3.77:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP
10.10.3.77:5060;rport=5060;received=10.10.3.77;branch=z9hG4bK259bf4a5
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
CSeq: 105 NOTIFY
Contact: <sip:321 at 10.10.3.150:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Content-Length: 0
--end msg--
13:44:59.236 pjsua_core.c RX 607 bytes Request msg NOTIFY/cseq=106
(rdata0x7f2064000908) from UDP 10.10.3.77:5060:
NOTIFY sip:321 at 10.10.3.150:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.3.77:5060;branch=z9hG4bK259bf4a5;rport
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150:5060>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
Contact: <sip:unknown at 10.10.3.77>
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
CSeq: 106 NOTIFY
User-Agent: Asterisk PBX (digium)
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 92
Messages-Waiting: yes
Message-Account: sip:voicemail at 10.10.3.77
Voice-Message: 1/5 (0/0)
--end msg--
13:44:59.236 pjsua_core.c TX 497 bytes Response msg 200/NOTIFY/cseq=105
(tdta0x7f20640048b0) to UDP 10.10.3.77:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP
10.10.3.77:5060;rport=5060;received=10.10.3.77;branch=z9hG4bK259bf4a5
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
CSeq: 105 NOTIFY
Contact: <sip:321 at 10.10.3.150:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Content-Length: 0
--end msg--
13:45:00.236 pjsua_core.c RX 607 bytes Request msg NOTIFY/cseq=106
(rdata0x7f2064000908) from UDP 10.10.3.77:5060:
NOTIFY sip:321 at 10.10.3.150:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.3.77:5060;branch=z9hG4bK259bf4a5;rport
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150:5060>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
Contact: <sip:unknown at 10.10.3.77>
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
CSeq: 106 NOTIFY
User-Agent: Asterisk PBX (digium)
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 92
Messages-Waiting: yes
Message-Account: sip:voicemail at 10.10.3.77
Voice-Message: 1/5 (0/0)
--end msg--
13:45:00.236 pjsua_core.c TX 497 bytes Response msg 200/NOTIFY/cseq=105
(tdta0x7f20640048b0) to UDP 10.10.3.77:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP
10.10.3.77:5060;rport=5060;received=10.10.3.77;branch=z9hG4bK259bf4a5
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
CSeq: 105 NOTIFY
Contact: <sip:321 at 10.10.3.150:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Content-Length: 0
--end msg--
13:45:02.235 pjsua_core.c RX 607 bytes Request msg NOTIFY/cseq=106
(rdata0x7f2064000908) from UDP 10.10.3.77:5060:
NOTIFY sip:321 at 10.10.3.150:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.3.77:5060;branch=z9hG4bK259bf4a5;rport
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150:5060>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
Contact: <sip:unknown at 10.10.3.77>
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
CSeq: 106 NOTIFY
User-Agent: Asterisk PBX (digium)
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 92
Messages-Waiting: yes
Message-Account: sip:voicemail at 10.10.3.77
Voice-Message: 1/5 (0/0)
--end msg--
13:45:02.235 pjsua_core.c TX 497 bytes Response msg 200/NOTIFY/cseq=105
(tdta0x7f20640048b0) to UDP 10.10.3.77:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP
10.10.3.77:5060;rport=5060;received=10.10.3.77;branch=z9hG4bK259bf4a5
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
CSeq: 105 NOTIFY
Contact: <sip:321 at 10.10.3.150:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Content-Length: 0
--end msg--
13:45:06.236 pjsua_core.c RX 607 bytes Request msg NOTIFY/cseq=106
(rdata0x7f2064000908) from UDP 10.10.3.77:5060:
NOTIFY sip:321 at 10.10.3.150:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.3.77:5060;branch=z9hG4bK259bf4a5;rport
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150:5060>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
Contact: <sip:unknown at 10.10.3.77>
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
CSeq: 106 NOTIFY
User-Agent: Asterisk PBX (digium)
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 92
Messages-Waiting: yes
Message-Account: sip:voicemail at 10.10.3.77
Voice-Message: 1/5 (0/0)
--end msg--
13:45:06.236 pjsua_core.c TX 497 bytes Response msg 200/NOTIFY/cseq=105
(tdta0x7f20640048b0) to UDP 10.10.3.77:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP
10.10.3.77:5060;rport=5060;received=10.10.3.77;branch=z9hG4bK259bf4a5
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
CSeq: 105 NOTIFY
Contact: <sip:321 at 10.10.3.150:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Content-Length: 0
--end msg--
13:45:10.237 pjsua_core.c RX 607 bytes Request msg NOTIFY/cseq=106
(rdata0x7f2064000908) from UDP 10.10.3.77:5060:
NOTIFY sip:321 at 10.10.3.150:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.3.77:5060;branch=z9hG4bK259bf4a5;rport
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150:5060>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
Contact: <sip:unknown at 10.10.3.77>
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
CSeq: 106 NOTIFY
User-Agent: Asterisk PBX (digium)
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 92
Messages-Waiting: yes
Message-Account: sip:voicemail at 10.10.3.77
Voice-Message: 1/5 (0/0)
--end msg--
13:45:10.237 pjsua_core.c TX 497 bytes Response msg 200/NOTIFY/cseq=105
(tdta0x7f20640048b0) to UDP 10.10.3.77:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP
10.10.3.77:5060;rport=5060;received=10.10.3.77;branch=z9hG4bK259bf4a5
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
CSeq: 105 NOTIFY
Contact: <sip:321 at 10.10.3.150:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Content-Length: 0
--end msg--
13:45:14.234 pjsua_core.c RX 607 bytes Request msg NOTIFY/cseq=106
(rdata0x7f2064000908) from UDP 10.10.3.77:5060:
NOTIFY sip:321 at 10.10.3.150:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.3.77:5060;branch=z9hG4bK259bf4a5;rport
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150:5060>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
Contact: <sip:unknown at 10.10.3.77>
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
CSeq: 106 NOTIFY
User-Agent: Asterisk PBX (digium)
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 92
Messages-Waiting: yes
Message-Account: sip:voicemail at 10.10.3.77
Voice-Message: 1/5 (0/0)
--end msg--
13:45:14.235 pjsua_core.c TX 497 bytes Response msg 200/NOTIFY/cseq=105
(tdta0x7f20640048b0) to UDP 10.10.3.77:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP
10.10.3.77:5060;rport=5060;received=10.10.3.77;branch=z9hG4bK259bf4a5
Call-ID: 4ab61803-46e1-40e1-98be-a78db0194774
From: "unknown" <sip:unknown@10.10.3.77>;tag=as6f7c1371
To: <sip:sip:321 at 10.10.3.150>;tag=3b9c5916-6bdb-45d6-b666-15a37784047d
CSeq: 105 NOTIFY
Contact: <sip:321 at 10.10.3.150:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Content-Length: 0
--end msg--
^C
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.pjsip.org/pipermail/pjsip_lists.pjsip.org/attachments/20110707/5803c729/attachment-0001.html>
