Hello Daniel,
I´ve reproduced the scenario with Kamailio version 4.1.3. Behaviour is the same
and this is the output from kamailio-4.1.3 with debug=3:
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: INFO:
-<|XLOG|>-: <PRESENCE> handle_subscribe From: sip:117711@10.16.48.14
executed
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [event_list.c:351]: search_event(): start event= [dialog/5]
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [subscribe.c:1098]: extract_sdialog_info(): 'Expires' header found,
value= 900
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [subscribe.c:1120]: extract_sdialog_info(): 'To' header ALREADY PARSED:
<sip:116001@10.16.48.44>
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [subscribe.c:1191]: extract_sdialog_info(): generating to_tag
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [subscribe.c:1251]: extract_sdialog_info(): subs->contact=
sip:117711@10.16.48.14:5070 - len = 27
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [subscribe.c:981]: handle_subscribe(): subscription status= active -
found in watcher table
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:117]: printf_subs(): pres_uri: sip:116001@10.16.48.44
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:118]: printf_subs(): watcher_user@watcher_domain:
117711(a)10.16.48.14
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:119]: printf_subs(): to_user@to_domain: 116001(a)10.16.48.44
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:120]: printf_subs(): from_user@from_domain:
117711(a)10.16.48.14
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:121]: printf_subs(): callid/from_tag/to_tag:
1543162531/749132449/4f7a7e54f75c89f5b968c90011d693b5-56dd
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:122]: printf_subs(): local_cseq/remote_cseq: 0/20
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:123]: printf_subs(): local_contact/contact:
sip:10.16.48.44:5060/sip:117711@10.16.48.14:5070
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:124]: printf_subs(): record_route:
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:125]: printf_subs(): sockinfo_str: udp:10.16.48.44:5060
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:127]: printf_subs(): event: dialog
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:128]: printf_subs(): status: active
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:129]: printf_subs(): reason:
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:130]: printf_subs(): version: 1
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:131]: printf_subs(): expires: 900
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:133]: printf_subs(): updated/updated_winfo: 46/-1
May 6 09:08:54 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [subscribe.c:354]: insert_subs_db(): inserting subscription in
active_watchers table
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [event_list.c:351]: search_event(): start event= [dialog/5]
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:1471]: send_notify_request(): dialog info:
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:117]: printf_subs(): pres_uri: sip:116001@10.16.48.44
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:118]: printf_subs(): watcher_user@watcher_domain:
117711(a)10.16.48.14
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:119]: printf_subs(): to_user@to_domain: 116001(a)10.16.48.44
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:120]: printf_subs(): from_user@from_domain:
117711(a)10.16.48.14
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:121]: printf_subs(): callid/from_tag/to_tag:
1543162531/749132449/4f7a7e54f75c89f5b968c90011d693b5-56dd
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:122]: printf_subs(): local_cseq/remote_cseq: 1/20
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:123]: printf_subs(): local_contact/contact:
sip:10.16.48.44:5060/sip:117711@10.16.48.14:5070
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:124]: printf_subs(): record_route:
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:125]: printf_subs(): sockinfo_str: udp:10.16.48.44:5060
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:127]: printf_subs(): event: dialog
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:128]: printf_subs(): status: active
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:129]: printf_subs(): reason:
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:130]: printf_subs(): version: 2
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:131]: printf_subs(): expires: 898
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:133]: printf_subs(): updated/updated_winfo: 46/-1
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [hash.c:461]: search_phtable(): pres_uri= sip:116001@10.16.48.44
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:616]: get_p_notify_body(): No record exists in hash_table
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence_dialoginfo [notify_body.c:75]: dlginfo_agg_nbody(): [pres_user]=116001
[pres_domain]= 10.16.48.44, [n]=0
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:1525]: send_notify_request(): Could not get the notify_body
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:1564]: send_notify_request(): headers:#012Max-Forwards:
70#015#012Event: dialog#015#012Contact:
<sip:10.16.48.44:5060>#015#012Subscription-State: active;expires=898#015#012
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:926]: ps_build_dlg_t(): CONTACT = sip:117711@10.16.48.14:5070
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:1574]: send_notify_request(): expires 898 status 1
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:1727]: shm_dup_cbparam(): === 22/6/37
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: INFO:
presence [notify.c:1601]: send_notify_request(): NOTIFY sip:117711@10.16.48.14
via sip:117711@10.16.48.14:5070 on behalf of sip:116001@10.16.48.44 for event
dialog
May 6 09:08:56 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:1701]: p_tm_callback(): completed with status 200
[to_tag:4f7a7e54f75c89f5b968c90011d693b5-56dd]
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: INFO:
-<|XLOG|>-: <PRESENCE> handle_publish From: sip:117103@172.31.60.87 executed
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [event_list.c:351]: search_event(): start event= [dialog/5]
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [publish.c:318]: handle_publish(): SIP-If-Match header not found
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [presentity.c:87]: generate_ETag(): etag= a.1399360111.20480.4.0 /
22#012
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [publish.c:327]: handle_publish(): new etag = a.1399360111.20480.4.0
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [publish.c:352]: handle_publish(): Expires header found, value= 1800
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [publish.c:396]: handle_publish(): KFe - the PUBLISH body is
processed...
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [publish.c:407]: handle_publish(): KFe - the content length is: 962
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [publish.c:444]: handle_publish(): KFe - event->evs_publ_handl is
executed...
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [publish.c:467]: handle_publish(): KFe - update_presentity is executed
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [publish.c:468]: handle_publish(): KFe - body = <?xml
version="1.0"?>#015#012<dialog-info
xmlns="urn:ietf:params:xml:ns:dialog-info"
version="00000000004" state="full"
entity="sip:117103@172.31.60.87">#015#012<dialog
id="CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
call-id="CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
direction="recipient">#015#012<state>terminated</state>#015#012<remote>#015#012<identity>sip:1101015004@172.31.60.13</identity>#015#012<target
uri="sip:1101015004@172.31.60.13"/>#015#012</remote>#015#012<local>#015#012<identity>sip:117103@172.31.60.87</identity>#015#012<target
uri="sip:117103@172.31.60.87"/>#015#012</local>#015#012</dialog>#015#012<dialog
id="1041054395-29684904-1398759995534(a)172.31.60.53"
call-id="1041054395-29684904-1398759995534(a)172.31.60.53"
direction="initiator">#015#012<state>confirmed</state>#015#012<remote>#015#012<identity>sip:117101@172.31.60.87</identity>#015#012<target
uri="sip:117101@172.31.60.87"/>#015#012</remote>#015#012<local>#015#012<identity>sip:117103@172.31.60.87</identity>#015#012<target
uri="sip:117103@172.31.60.87"/>#015#012</local>#015#012</dialog>#015#012</dialog-info>#015#012
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [hash.c:461]: search_phtable(): pres_uri= sip:116001@10.16.48.44
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [presentity.c:398]: update_presentity(): inserting 8 cols into table
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [presentity.c:104]: publ_send200ok(): send 200OK reply
May 6 09:09:00 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [presentity.c:105]: publ_send200ok(): etag= a.1399360111.20480.4.0 -
len= 22
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [event_list.c:351]: search_event(): start event= [dialog/5]
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:1471]: send_notify_request(): dialog info:
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:117]: printf_subs(): pres_uri: sip:116001@10.16.48.44
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:118]: printf_subs(): watcher_user@watcher_domain:
117711(a)10.16.48.14
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:119]: printf_subs(): to_user@to_domain: 116001(a)10.16.48.44
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:120]: printf_subs(): from_user@from_domain:
117711(a)10.16.48.14
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:121]: printf_subs(): callid/from_tag/to_tag:
1543162531/749132449/4f7a7e54f75c89f5b968c90011d693b5-56dd
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:122]: printf_subs(): local_cseq/remote_cseq: 2/20
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:123]: printf_subs(): local_contact/contact:
sip:10.16.48.44:5060/sip:117711@10.16.48.14:5070
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:124]: printf_subs(): record_route:
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:125]: printf_subs(): sockinfo_str: udp:10.16.48.44:5060
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:127]: printf_subs(): event: dialog
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:128]: printf_subs(): status: active
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:129]: printf_subs(): reason:
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:130]: printf_subs(): version: 3
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:131]: printf_subs(): expires: 893
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:133]: printf_subs(): updated/updated_winfo: 46/-1
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [hash.c:461]: search_phtable(): pres_uri= sip:116001@10.16.48.44
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:744]: get_p_notify_body(): Event requires aggregation
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence_dialoginfo [notify_body.c:75]: dlginfo_agg_nbody(): [pres_user]=116001
[pres_domain]= 10.16.48.44, [n]=1
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence_dialoginfo [notify_body.c:126]: agregate_xmls(): [pres_user]=116001
[pres_domain]= 10.16.48.44, [n]=1
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence_dialoginfo [notify_body.c:145]: agregate_xmls(): parsing XML body:
[n]=1, [i]=0, [j]=0 xml_array[j]=0x9bef820
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence_dialoginfo [notify_body.c:166]: agregate_xmls(): number of bodies in
total [n]=1, number of useful bodies [j]=1
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence_dialoginfo [notify_body.c:210]: agregate_xmls(): [n]=1, [i]=0, [j]=1
xml_array[i]=0xc0c0c0c0
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence_dialoginfo [notify_body.c:219]: agregate_xmls(): node type: Element,
name: dialog
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence_dialoginfo [notify_body.c:81]: dlginfo_agg_nbody(): [n_body]=0xb7a9d298
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence_dialoginfo [notify_body.c:84]: dlginfo_agg_nbody(): [*n_body]=<?xml
version="1.0"?>#012<dialog-info
xmlns="urn:ietf:params:xml:ns:dialog-info"
version="00000000000" state="full"
entity="sip:116001@10.16.48.44">#012 <dialog
id="CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
call-id="CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
direction="recipient">#012<state>terminated</state>#012<remote>#012<identity>sip:1101015004@172.31.60.13</identity>#012<target
uri="sip:1101015004@172.31.60.13"/>#012</remote>#012<local>#012<identity>sip:117103@172.31.60.87</identity>#012<target
uri="sip:117103@172.31.60.87"/>#012</local>#012</dialog>#012</dialog-info>#012
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:1564]: send_notify_request(): headers:#012Max-Forwards:
70#015#012Event: dialog#015#012Contact:
<sip:10.16.48.44:5060>#015#012Subscription-State:
active;expires=893#015#012Content-Type: application/dialog-info+xml#015#012
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:926]: ps_build_dlg_t(): CONTACT = sip:117711@10.16.48.14:5070
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:1574]: send_notify_request(): expires 893 status 1
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: DEBUG:
presence [notify.c:1727]: shm_dup_cbparam(): === 22/6/37
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20485]: INFO:
presence [notify.c:1601]: send_notify_request(): NOTIFY sip:117711@10.16.48.14
via sip:117711@10.16.48.14:5070 on behalf of sip:116001@10.16.48.44 for event
dialog
May 6 09:09:01 sipsrvnode1 /usr/local/kamailio41/sbin/kamailio[20480]: DEBUG:
presence [notify.c:1701]: p_tm_callback(): completed with status 200
[to_tag:4f7a7e54f75c89f5b968c90011d693b5-56dd]
The DB query returned the whole body incl. 2 dialog entries, as traced with
Wireshark:
MySQL Query/Result, traced with Wireshark
Command: Query
Statement: select body,etag,sender from presentity where domain='10.16.48.44'
AND username='116001' AND event='dialog' order by received_time
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info"
version="00000000004"
state="full" entity="sip:117103@172.31.60.87">
<dialog id="CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
call-id="CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
direction="recipient">
<state>terminated</state>
<remote>
<identity>sip:1101015004@172.31.60.13</identity>
<target uri="sip:1101015004@172.31.60.13"/>
</remote>
<local>
<identity>sip:117103@172.31.60.87</identity>
<target uri="sip:117103@172.31.60.87"/>
</local>
</dialog>
<dialog id="1041054395-29684904-1398759995534(a)172.31.60.53"
call-id="1041054395-29684904-1398759995534(a)172.31.60.53"
direction="initiator">
<state>confirmed</state>
<remote>
<identity>sip:117101@172.31.60.87</identity>
<target uri="sip:117101@172.31.60.87"/>
</remote>
<local>
<identity>sip:117103@172.31.60.87</identity>
<target uri="sip:117103@172.31.60.87"/>
</local>
</dialog>
</dialog-info>
a.1399360111.20480.4.0
regards,
Klaus
Daniel-Constantin Mierla <miconda(a)gmail.com> hat
am 5. Mai 2014 um 17:37
geschrieben:
Can you try with the latest version 4.1.x? It is where I looked in the code
and seemed to walk through all dialog nodes.
Cheers, Daniel
On 05/05/14 16:28, Klaus Feichtinger wrote:
> > this is the output (in this example version 3.2.4) in debug
> > level 3 after receiving a PUBLISH request (incl. forming the NOTIFY
> > request):
>
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [event_list.c:350]: start event= [dialog/5]
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [publish.c:349]: SIP-If-Match header not found
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [presentity.c:85]: etag= a.1399299676.23439.2.0 / 22#012
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [publish.c:358]: new etag = a.1399299676.23439.2.0
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [publish.c:383]: Expires header found, value= 1800
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [publish.c:468]: KLAUSDBG - body = <?xml
version="1.0"?>#015#012<dialog-info
> xmlns="urn:ietf:params:xml:ns:dialog-info"
version="00000000004"
> state="full" entity= "sip:117103@172.31.60.87"
<sip:117103@172.31.60.87>
> >#015#012<dialog id=
"CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
> <mailto:CBE263FF-CEAE11E3-80E8CCBC-52135ACA@172.31.60.13> call-id=
> "CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
> <mailto:CBE263FF-CEAE11E3-80E8CCBC-52135ACA@172.31.60.13>
>
direction="recipient">#015#012<state>terminated</state>#015#012<remote>#015#012<identity><sip:1101015004@172.31.60.13>
> </identity>#015#012<target uri= "sip:1101015004@172.31.60.13"
> <sip:1101015004@172.31.60.13>
>
/>#015#012</remote>#015#012<local>#015#012<identity><sip:117103@172.31.60.87>
> </identity>#015#012<target uri= "sip:117103@172.31.60.87"
> <sip:117103@172.31.60.87>
/>#015#012</local>#015#012</dialog>#015#012<dialog
> id= "1041054395-29684904-1398759995534(a)172.31.60.53"
> <mailto:1041054395-29684904-1398759995534@172.31.60.53> call-id=
> "1041054395-29684904-1398759995534(a)172.31.60.53"
> <mailto:1041054395-29684904-1398759995534@172.31.60.53>
>
direction="initiator">#015#012<state>confirmed</state>#015#012<remote>#015#012<identity><sip:117101@172.31.60.87>
> </identity>#015#012<target uri= "sip:117101@172.31.60.87"
> <sip:117101@172.31.60.87>
>
/>#015#012</remote>#015#012<local>#015#012<identity><sip:117103@172.31.60.87>
> </identity>#015#012<target uri= "sip:117103@172.31.60.87"
> <sip:117103@172.31.60.87>
>
/>#015#012</local>#015#012</dialog>#015#012</dialog-info>#015#012
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [hash.c:470]: pres_uri=<sip:116001@10.16.48.44>
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [presentity.c:385]: inserting 8 cols into table
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [presentity.c:99]: send 200OK reply
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [presentity.c:100]: etag= a.1399299676.23439.2.0 - len= 22
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:1041]: querying database table = active_watchers
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:1116]: found 1 dialogs
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:122]: #012#011[pres_uri]= sip:116001@10.16.48.44#012#011[to_user]=
> 116001#011[to_domain]= 10.16.48.44#012#011[w_user]= 117700#011[w_domain]=
> 10.16.48.14#012#011[event]= dialog#012#011[status]= active#012#011[expires]=
> 889#012#011[callid]= 1146821297#011[local_cseq]=1#012#011[to_tag]=
> 4f7a7e54f75c89f5b968c90011d693b5-8c7d#011[from_tag]=
> 154174339#012#011[contact]=<sip:117700@10.16.48.14:5070#011> [record_route]=
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:1333]: found 1 dialogs( 1 in database and 0 in hash_table)
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:782]: Event requires aggregation
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG:
> presence_dialoginfo [notify_body.c:67]: [pres_user]=116001 [pres_domain]=
> 10.16.48.44, [n]=1
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG:
> presence_dialoginfo [notify_body.c:107]: [pres_user]=116001 [pres_domain]=
> 10.16.48.44, [n]=1
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG:
> presence_dialoginfo [notify_body.c:199]: node type: Element, name: dialog
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG:
> presence_dialoginfo [notify_body.c:73]: [n_body]=0xb7a6daa4
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: 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=
"116001(a)10.16.48.44"
> <mailto:116001@10.16.48.44> >#012 <dialog id=
> "CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
> <mailto:CBE263FF-CEAE11E3-80E8CCBC-52135ACA@172.31.60.13> call-id=
> "CBE263FF-CEAE11E3-80E8CCBC-52135ACA(a)172.31.60.13"
> <mailto:CBE263FF-CEAE11E3-80E8CCBC-52135ACA@172.31.60.13>
>
direction="recipient">#012<state>terminated</state>#012<remote>#012<identity><sip:1101015004@172.31.60.13>
> </identity>#012<target uri= "sip:1101015004@172.31.60.13"
> <sip:1101015004@172.31.60.13>
>
/>#012</remote>#012<local>#012<identity><sip:117103@172.31.60.87>
> </identity>#012<target uri= "sip:117103@172.31.60.87"
> <sip:117103@172.31.60.87>
/>#012</local>#012</dialog>#012</dialog-info>#012
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG:
> presence_dialoginfo [notify_body.c:328]: replace version with "1"
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:1651]: updating subscription to database
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:1468]: dialog info:
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:122]: #012#011[pres_uri]= sip:116001@10.16.48.44#012#011[to_user]=
> 116001#011[to_domain]= 10.16.48.44#012#011[w_user]= 117700#011[w_domain]=
> 10.16.48.14#012#011[event]= dialog#012#011[status]= active#012#011[expires]=
> 889#012#011[callid]= 1146821297#011[local_cseq]=1#012#011[to_tag]=
> 4f7a7e54f75c89f5b968c90011d693b5-8c7d#011[from_tag]=
> 154174339#012#011[contact]=<sip:117700@10.16.48.14:5070#011> [record_route]=
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:236]: expires = 889
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:1562]: headers:#012Max-Forwards: 70#015#012Event:
> dialog#015#012Contact: <sip:10.16.48.44:5060> <sip:10.16.48.44:5060>
> #015#012Subscription-State: active;expires=870#015#012Content-Type:
> application/dialog-info+xml#015#012
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:964]: CONTACT =<sip:117700@10.16.48.14:5070>
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:1724]: === 22/6/37
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: INFO: presence
> [notify.c:1593]: NOTIFY<sip:117700@10.16.48.14>
> via<sip:117700@10.16.48.14:5070> on behalf of<sip:116001@10.16.48.44>
for
> event dialog
> May 5 16:21:49 sipsrvnode1 /usr/sbin/kamailio[23439]: DEBUG: presence
> [notify.c:1689]: completed with status 200
> [to_tag:4f7a7e54f75c89f5b968c90011d693b5-8c7d]
>
> Main visible difference is the xml body output between PUBLISH
> (publish.c) and NOTIFY (notify_body.c).
>
> regards,
> Klaus
>
> >