New subject: SIP NOTIFY problem in 'presence_dialoginfo' module?

30 Mar 2011


      Hello list,
I have a special situation in which string characters of the "root-line"
of the notify-body are overwritten by Kamailio. In detail: the root-line
of the NOTIFY message sent to the subscriber looks like:
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="1" ll"
entity="sip:117090@10.16.10.99"> instead of
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="1"
state="full" entity="sip:117090@10.16.10.99"> In other words: the string
state="full" is overwritten by space characters. Therefore the message
is no longer "valid" and the parser of the subscriber-user agent has
problems....
The exact scenario in my use case is, that user agents can subscribe the
events "presence" and "dialog" on Kamailio. The information about
presence and dialog-states is published to Kamailio by PUBLISH messages
from the user agents themselves. Kamailio does not have to generate this
information itself. In the following lines I have an excerpt of the
signalisation: 1) initial subscription of party A, 2) the responded
notification (without body) 3) subscription of party B 4) the responded
notification (with body) 5) a publish message of the subscribed party B
with actual dialog information and 6) the notification with body to the
subscriber A.
1) Initial SUBSCRIBE message of party A:
======================================SUBSCRIBE sip:117090@10.16.10.99
SIP/2.0 Via: SIP/2.0/UDP 10.16.10.93:5060;rport;branch=z9hG4bK1411449981
From: sip:117093@10.16.10.99;tag=2453899634-24035392-1301468026894 To:
sip:117090@10.16.10.99
Call-ID: 2442490492-24035392-1301468026894@10.16.10.93
CSeq: 20 SUBSCRIBE
Contact: sip:117093@10.16.10.93:5060
Max-Forwards: 70
User-Agent: SipTapi
Expires: 3600
Event: dialog
Content-Length: 0
2) Responded NOTIFY message from Kamailio:
========================================NOTIFY
sip:117093@10.16.10.93:5060 SIP/2.0 Via: SIP/2.0/UDP
10.16.10.99;branch=z9hG4bK7cc7.08e060b6000000000000000000000000.0
To: sip:117093@10.16.10.99;tag=2453899634-24035392-1301468026894
From: sip:117090@10.16.10.99;tag=a23c71953194c2c72e41c4d20e4f7127-86e1
CSeq: 1 NOTIFY
Call-ID: 2442490492-24035392-1301468026894@10.16.10.93
Content-Length: 0
User-Agent: kamailio (3.1.2 (i386/linux))
Max-Forwards: 70
Event: dialog
Contact: sip:10.16.10.99:5060
Subscription-State: active;expires=3670
3) Initial SUBSCRIBE message of party B:
======================================SUBSCRIBE sip:117093@10.16.10.99
SIP/2.0 Via: SIP/2.0/UDP 10.16.10.90:5060;rport;branch=z9hG4bK4016956575
From: sip:117090@10.16.10.99;tag=2605346227-26329880-1301468174702 To:
sip:117093@10.16.10.99
Call-ID: 2982039389-26329880-1301468174702@10.16.10.90
CSeq: 20 SUBSCRIBE
Contact: sip:117090@10.16.10.90:5060
Max-Forwards: 70
User-Agent: SipTapi
Expires: 3600
Event: dialog
Content-Length: 0
4) Responded NOTIFY message from Kamailio (with version number
"00000000000"!!!!):
==============================================================================NOTIFY
sip:117090@10.16.10.90:5060 SIP/2.0 Via: SIP/2.0/UDP
10.16.10.99;branch=z9hG4bK10e8.31cb2284000000000000000000000000.0
To: sip:117090@10.16.10.99;tag=2605346227-26329880-1301468174702
From: sip:117093@10.16.10.99;tag=a23c71953194c2c72e41c4d20e4f7127-5f56
CSeq: 1 NOTIFY
Call-ID: 2982039389-26329880-1301468174702@10.16.10.90
Content-Length: 593
User-Agent: kamailio (3.1.2 (i386/linux))
Max-Forwards: 70
Event: dialog
Contact: sip:10.16.10.99:5060
Subscription-State: active;expires=3670
Content-Type: application/dialog-info+xml
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info"
version="00000000000" state="full" entity="117093@10.16.10.99">
  <dialog id="3375446242-26591296-1301467877329@10.16.10.93"
call-id="3375446242-26591296-1301467877329@10.16.10.93"
direction="initiator">
    <state>terminated</state>
    <remote>
      <identity>sip:019992116002@10.16.10.99</identity>
      <target uri="sip:019992116002@10.16.10.99"/>
    </remote>
    <local>
      <identity>sip:117093@10.16.10.99</identity>
      <target uri="sip:117093@10.16.10.99"/>
    </local>
  </dialog>
</dialog-info>
5) The subscribed party is sending a PUBLISH message with following
information:
============================================================================PUBLISH
sip:117090@10.16.10.99 SIP/2.0 Via: SIP/2.0/UDP
10.16.10.90:5060;rport;branch=z9hG4bK348084694
From: sip:117090@10.16.10.99;tag=3644648667-26329880-1301468223499 To:
sip:117090@10.16.10.99
Call-ID: 332031778-26329880-1301468223499@10.16.10.90
CSeq: 20 PUBLISH
Max-Forwards: 70
User-Agent: SipTapi
Content-Disposition: render;handling=required
Expires: 3600
Event: dialog
Content-Type: application/dialog-info+xml
Content-Length:   592
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="4"
state="full" entity="sip:117090@10.16.10.99">
  <dialog id="2769397361-26329880-1301468223108@10.16.10.90"
call-id="2769397361-26329880-1301468223108@10.16.10.90"
direction="initiator">
    <state>confirmed</state>
    <remote>
      <identity>sip:116001@10.16.10.99</identity>
      <target uri="<sip:116001@10.16.10.99>"/>
    </remote>
    <local>
      <identity>sip:117090@10.16.10.99</identity>
      <target uri="sip:117090@10.16.10.99"/>
    </local>
  </dialog>
</dialog-info>
6) Status informative NOTIFY message from Kamailio (built from the
PUBLISH message above - with correct version but string overwriting!!!):
=======================================================================================================================================NOTIFY
sip:117093@10.16.10.93:5060 SIP/2.0 Via: SIP/2.0/UDP
10.16.10.99;branch=z9hG4bK4cc7.faa8dc87000000000000000000000000.0
To: sip:117093@10.16.10.99;tag=2453899634-24035392-1301468026894
From: sip:117090@10.16.10.99;tag=a23c71953194c2c72e41c4d20e4f7127-86e1
CSeq: 2 NOTIFY
Call-ID: 2442490492-24035392-1301468026894@10.16.10.93
Content-Length: 592
User-Agent: kamailio (3.1.2 (i386/linux))
Max-Forwards: 70
Event: dialog
Contact: sip:10.16.10.99:5060
Subscription-State: active;expires=3570
Content-Type: application/dialog-info+xml
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="1" ll"
entity="sip:117090@10.16.10.99">
  <dialog id="2769397361-26329880-1301468223108@10.16.10.90"
call-id="2769397361-26329880-1301468223108@10.16.10.90"
direction="initiator">
    <state>confirmed</state>
    <remote>
      <identity>sip:116001@10.16.10.99</identity>
      <target uri="<sip:116001@10.16.10.99>"/>
    </remote>
    <local>
      <identity>sip:117090@10.16.10.99</identity>
      <target uri="sip:117090@10.16.10.99"/>
    </local>
  </dialog>
</dialog-info>
Debug information of Kamailio and information in the source code show
that the version number "00000000000" is a placeholder only, which
should be replaced with a valid version number. However, it seems that
there is a problem in handling these strings. The version number is
replaced, but in case that the version id is only one character long,
ten space characters are inserted- overwriting other information......
Can anybody comment this problem? Is this a bug of the
presence_dialoginfo- or another module?
Thanks in advance!
Regards,
Klaus
P.S. additional information from source code an debug output of
kamailio:
notify_body.c:
[...]
/* The version must be increased for each new document and is a 32bit
int.
 As the version is different for each watcher, we can not set here the
correct value. Thus, we just put here a placeholder which will be
   replaced by the correct value in the aux_body_processing callback.
Thus we have CPU intensive XML aggregation only once and can use
quick search&replace in the per-watcher aux_body_processing callback.
We use 11 chracters as an signed int (although RFC says unsigned int
we use signed int as presence module stores "version" in DB as
   signed int) has max. 10 characters + 1 character for the sign
*/
[...]
Debug information from Kamailio:
Ad 4)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:67]: [pres_user]=117093 [pres_domain]= 10.16.10.99, [n]=1
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:107]: [pres_user]=117093 [pres_domain]= 10.16.10.99,
[n]=1 SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:199]: node type: Element, name: dialog
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:73]: [n_body]=0x835fe54
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:76]: [*n_body]=<?xml version="1.0"?>#012<dialog-info
xmlns="urn:ietf:params:xml:ns:dialog-info" version="00000000000"
state="full" entity="117093@10.16.10.99">#012  <dialog
id="6b1de4df-6c9ce978@10.16.10.203"
call-id="6b1de4df-6c9ce978@10.16.10.203" direction="recipient">#012
<state>confirmed</state>#012    <remote>#012
<identity>sip:116001@10.16.10.99</identity>#012      <target
uri="sip:116001@10.16.10.99"/>#012    </remote>#012    <local>#012
<identity>sip:117093@10.16.10.99</identity>#012      <target
uri="sip:117093@10.16.10.99"/>#012    </local>#012
</dialog>#012</dialog-info>#012
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:328]: replace version with "1"
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence [notify.c:1461]:
dialog info:
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence [notify.c:122]:
#012#011[pres_uri]=
sip:117093@10.16.10.99#012#011[to_user]117093#011[to_domain]=
10.16.10.99#012#011[w_user]=
117090#011[w_domain]10.16.10.99#012#011[event]= dialog#012#011[status]=
active#012#011[expires]3519#012#011[callid]3119346140-8635704-1301477522967@10.16.10.90#011[local_cseq]=1#012#011[to_tag
]=
a23c71953194c2c72e41c4d20e4f7127-7529#011[from_tag]2282475328-8635704-1301477522967#012#011[contact]sip:117090@10.16.10.90:5060#011[record_route]SipSrv1
/usr/sbin/kamailio[26764]: DEBUG: presence [notify.c:234]: expires 3519
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence [notify.c:1555]:
headers:#012Max-Forwards: 70#015#012Event: dialog#015#012Contact:
sip:10.16.10.99:5060#015#012Subscription-State:
active;expires=3570#015#012Content-Type:
application/dialog-info+xml#015#012 SipSrv1 /usr/sbin/kamailio[26764]:
DEBUG: presence [notify.c:940]: CONTACT sip:117090@10.16.10.90:5060
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [socket_info.c:501]:
grep_sock_info - checking if host==us: 11==11 &&  [10.16.10.99]
=[10.16.10.99] SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core>
[socket_info.c:504]: grep_sock_info - checking if port 5060 matches port
5060
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence [notify.c:1729]:
==22/6/37 SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: tm [uac.c:240]:
DEBUG:tm:t_uac: next_hop=sip:117090@10.16.10.90:5060
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: tm [uac.c:181]: DEBUG:
dlg2hash: 27355
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: INFO: presence [notify.c:1586]:
NOTIFY sip:117090@10.16.10.99 via sip:117090@10.16.10.90:5060 on behalf
of sip:117093@10.16.10.99 for event dialog
Ad 6)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:67]: [pres_user]=117093 [pres_domain]= 10.16.10.99, [n]=1
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:107]: [pres_user]=117093 [pres_domain]= 10.16.10.99,
[n]=1 SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:199]: node type: Element, name: dialog
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:73]: [n_body]=0x835fcb0
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:76]: [*n_body]=<?xml version="1.0"?>#012<dialog-info
xmlns="urn:ietf:params:xml:ns:dialog-info" version="00000000000"
state="full" entity="117093@10.16.10.99">#012  <dialog
id="6b1de4df-6c9ce978@10.16.10.203"
call-id="6b1de4df-6c9ce978@10.16.10.203" direction="recipient">#012
<state>terminated</state>#012    <remote>#012
<identity>sip:116001@10.16.10.99</identity>#012      <target
uri="sip:116001@10.16.10.99"/>#012    </remote>#012    <local>#012
<identity>sip:117093@10.16.10.99</identity>#012      <target
uri="sip:117093@10.16.10.99"/>#012    </local>#012
</dialog>#012</dialog-info>#012
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence_dialoginfo
[notify_body.c:328]: replace version with "2"
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence [notify.c:1461]:
dialog info:
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence [notify.c:122]:
#012#011[pres_uri]=
sip:117093@10.16.10.99#012#011[to_user]117093#011[to_domain]=
10.16.10.99#012#011[w_user]=
117090#011[w_domain]10.16.10.99#012#011[event]= dialog#012#011[status]=
active#012#011[expires]3242#012#011[callid]3119346140-8635704-1301477522967@10.16.10.90#011[local_cseq]=2#012#011[to_tag
]=
a23c71953194c2c72e41c4d20e4f7127-7529#011[from_tag]2282475328-8635704-1301477522967#012#011[contact]sip:117090@10.16.10.90:5060#011[record_route]=
 SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence [notify.c:234]:
expires 3242 SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence
[notify.c:1555]: headers:#012Max-Forwards: 70#015#012Event:
dialog#015#012Contact:
sip:10.16.10.99:5060#015#012Subscription-State:
active;expires=3270#015#012Content-Type:
application/dialog-info+xml#015#012 SipSrv1 /usr/sbin/kamailio[26764]:
DEBUG: presence [notify.c:940]: CONTACT sip:117090@10.16.10.90:5060
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [socket_info.c:501]:
grep_sock_info - checking if host==us: 11==11 &&  [10.16.10.99]
=[10.16.10.99] SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core>
[socket_info.c:504]: grep_sock_info - checking if port 5060 matches port
5060
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: presence [notify.c:1729]:
==22/6/37 SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: tm [uac.c:240]:
DEBUG:tm:t_uac: next_hop=sip:117090@10.16.10.90:5060
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: tm [uac.c:181]: DEBUG:
dlg2hash: 27356
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
SipSrv1 /usr/sbin/kamailio[26764]: INFO: presence [notify.c:1586]:
NOTIFY sip:117090@10.16.10.99 via sip:117090@10.16.10.90:5060 on behalf
of sip:117093@10.16.10.99 for event dialog

SIP NOTIFY problem in "presence_dialoginfo" module?