[SR-Users] SIP NOTIFY problem in "presence_dialoginfo" module?

Klaus Feichtinger klaus.lists at inode.at
Wed Mar 30 15:01:50 CEST 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 at 10.16.10.99"> instead of
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="1"
state="full" entity="sip:117090 at 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 at 10.16.10.99
SIP/2.0 Via: SIP/2.0/UDP 10.16.10.93:5060;rport;branch=z9hG4bK1411449981
From: <sip:117093 at 10.16.10.99>;tag=2453899634-24035392-1301468026894 To:
<sip:117090 at 10.16.10.99>
Call-ID: 2442490492-24035392-1301468026894 at 10.16.10.93
CSeq: 20 SUBSCRIBE
Contact: <sip:117093 at 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 at 10.16.10.93:5060 SIP/2.0 Via: SIP/2.0/UDP
10.16.10.99;branch=z9hG4bK7cc7.08e060b6000000000000000000000000.0
To: sip:117093 at 10.16.10.99;tag=2453899634-24035392-1301468026894
From: sip:117090 at 10.16.10.99;tag=a23c71953194c2c72e41c4d20e4f7127-86e1
CSeq: 1 NOTIFY
Call-ID: 2442490492-24035392-1301468026894 at 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 at 10.16.10.99
SIP/2.0 Via: SIP/2.0/UDP 10.16.10.90:5060;rport;branch=z9hG4bK4016956575
From: <sip:117090 at 10.16.10.99>;tag=2605346227-26329880-1301468174702 To:
<sip:117093 at 10.16.10.99>
Call-ID: 2982039389-26329880-1301468174702 at 10.16.10.90
CSeq: 20 SUBSCRIBE
Contact: <sip:117090 at 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 at 10.16.10.90:5060 SIP/2.0 Via: SIP/2.0/UDP
10.16.10.99;branch=z9hG4bK10e8.31cb2284000000000000000000000000.0
To: sip:117090 at 10.16.10.99;tag=2605346227-26329880-1301468174702
From: sip:117093 at 10.16.10.99;tag=a23c71953194c2c72e41c4d20e4f7127-5f56
CSeq: 1 NOTIFY
Call-ID: 2982039389-26329880-1301468174702 at 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 at 10.16.10.99">
  <dialog id="3375446242-26591296-1301467877329 at 10.16.10.93"
call-id="3375446242-26591296-1301467877329 at 10.16.10.93"
direction="initiator">
    <state>terminated</state>
    <remote>
      <identity>sip:019992116002 at 10.16.10.99</identity>
      <target uri="sip:019992116002 at 10.16.10.99"/>
    </remote>
    <local>
      <identity>sip:117093 at 10.16.10.99</identity>
      <target uri="sip:117093 at 10.16.10.99"/>
    </local>
  </dialog>
</dialog-info>

5) The subscribed party is sending a PUBLISH message with following
information:
============================================================================PUBLISH
sip:117090 at 10.16.10.99 SIP/2.0 Via: SIP/2.0/UDP
10.16.10.90:5060;rport;branch=z9hG4bK348084694
From: <sip:117090 at 10.16.10.99>;tag=3644648667-26329880-1301468223499 To:
<sip:117090 at 10.16.10.99>
Call-ID: 332031778-26329880-1301468223499 at 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 at 10.16.10.99">
  <dialog id="2769397361-26329880-1301468223108 at 10.16.10.90"
call-id="2769397361-26329880-1301468223108 at 10.16.10.90"
direction="initiator">
    <state>confirmed</state>
    <remote>
      <identity><sip:116001 at 10.16.10.99></identity>
      <target uri="<sip:116001 at 10.16.10.99>"/>
    </remote>
    <local>
      <identity>sip:117090 at 10.16.10.99</identity>
      <target uri="sip:117090 at 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 at 10.16.10.93:5060 SIP/2.0 Via: SIP/2.0/UDP
10.16.10.99;branch=z9hG4bK4cc7.faa8dc87000000000000000000000000.0
To: sip:117093 at 10.16.10.99;tag=2453899634-24035392-1301468026894
From: sip:117090 at 10.16.10.99;tag=a23c71953194c2c72e41c4d20e4f7127-86e1
CSeq: 2 NOTIFY
Call-ID: 2442490492-24035392-1301468026894 at 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 at 10.16.10.99">
  <dialog id="2769397361-26329880-1301468223108 at 10.16.10.90"
call-id="2769397361-26329880-1301468223108 at 10.16.10.90"
direction="initiator">
    <state>confirmed</state>
    <remote>
      <identity><sip:116001 at 10.16.10.99></identity>
      <target uri="<sip:116001 at 10.16.10.99>"/>
    </remote>
    <local>
      <identity>sip:117090 at 10.16.10.99</identity>
      <target uri="sip:117090 at 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 at 10.16.10.99">#012  <dialog
id="6b1de4df-6c9ce978 at 10.16.10.203"
call-id="6b1de4df-6c9ce978 at 10.16.10.203" direction="recipient">#012
<state>confirmed</state>#012    <remote>#012
<identity>sip:116001 at 10.16.10.99</identity>#012      <target
uri="sip:116001 at 10.16.10.99"/>#012    </remote>#012    <local>#012
<identity>sip:117093 at 10.16.10.99</identity>#012      <target
uri="sip:117093 at 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 at 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 at 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 at 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 at 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 at 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 at 10.16.10.99 via sip:117090 at 10.16.10.90:5060 on behalf
of sip:117093 at 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 at 10.16.10.99">#012  <dialog
id="6b1de4df-6c9ce978 at 10.16.10.203"
call-id="6b1de4df-6c9ce978 at 10.16.10.203" direction="recipient">#012
<state>terminated</state>#012    <remote>#012
<identity>sip:116001 at 10.16.10.99</identity>#012      <target
uri="sip:116001 at 10.16.10.99"/>#012    </remote>#012    <local>#012
<identity>sip:117093 at 10.16.10.99</identity>#012      <target
uri="sip:117093 at 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 at 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 at 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 at 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 at 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 at 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 at 10.16.10.99 via sip:117090 at 10.16.10.90:5060 on behalf
of sip:117093 at 10.16.10.99 for event dialog

More information about the sr-users mailing list