[kamailio/kamailio] presence: incorrect dialog state for multiple dialogs xml body (#1427)
5 Feb
2018
5 Feb
'18
1:50 p.m.
### Description
The issue started with this improvement:
https://github.com/kamailio/kamailio/commit/839cf89b02f8817156487a960ff6201…
(it works fine for single dialog bodies, but make a mess with multiple-dialog bodies)
### Troubleshooting
**Test scheme, preconditions:**
- SIP server: kamailio + Asterisk
- 3 SIP phones. UA-A, UA-B, UA-C
Kamailio is configured with presence+presence_dialoginfo modules.
Asterisk sends PUBLISHes regarding changes of dialog's state, kamailio process it
(handle_publish), and send NOTIFIYs to all subscribed endpoints
**Bug description** (the issue is considered from the point of view of UA-B's state):
- UA-A calls to UA-B => Asterisk send PUBLISHes (dialog UA-B1), UA-B (states on-the
Trying -> Proceeding -> Confirmed)
- UA-B makes attended transfer to UA-C (call answered) => Asterisk send PUBLISHes with
complex XML (2 dialogs state in a body. UA-B1(Confirmed) and new UA-B2 (Confirmed))
- UA-B completes the transfer, as a result, Asterisk sends (bodies from this 2 PUBLISHes
are below, in the SIP traffic section):
1. PUBLISH with multiple dialog body (UA-B1 - terminated, UA-B2 - confirmed) =>
processed OK
2. PUBLISH with single dialog body (UA-B2 - terminated.) => **Bug is here**
so now:
```
presentity.c:1084 checks is_dialog_terminated // check is dialog terminated for event:
dialog
presentity.c:549 calls get_dialog_state
// make a db query with the previous state (that query returnes: (UA-B1 -
terminated, UA-B2 - confirmed))
// loop through result returned from DB, call parse_dialog_state_from_body
presentity.c:307 - at this function:
...
node = xmlNodeGetChildByName(node, "dialog"); // return part
of xml with 2 dialogs
...
childNode = xmlNodeGetChildByName(node, "state"); // return
state of the first! dialog in a list, not the current dialog
...
due to obtained state is "terminated", if(is_dialog_terminated(presentity))
returnes TRUE
and subsequent code sends silently 200OK.
```
**Result:**
- those subscribed to dialog state of UA-B, do not recieve NOTIFY with a valid state
(BLFs remain "lighting")
**Attempts of workaround:**
- I tried to go to "send_412" logic when is_dialog_terminated (TRUE).
- But in the subsequent PUBLISH (state=terminated) Asterisk does not insert "call-id,
to-tag, from-tag" parameters, and endpoint fails to recognize which dialog is
terminated, and BLF remains to light.
#### SIP Traffic
not SIP, but only relevant part of XML bodies.
Multiple dialogs body, this one is last to succeed (look at the state of **first**
dialog)
```
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info"
version="36" state="full" entity="252">
<dialog id="3bf1a5de53394e394f7b0241067faccf"
call-id="3bf1a5de53394e394f7b0241067faccf" local-tag="as27f0e6f0"
remote-tag="1349583034" remote-uri="sip:252@10.100.1.24:5064"
local-uri="sip:251@127.0.0.1:6050" direction="recipient">
<note>Ready</note>
<remote>
<identity>252</identity>
<target uri="252">
</target>
</remote>
<local>
<identity>251</identity>
<target uri="251"/>
</local>
<state>terminated</state>
</dialog>
<dialog id="4070150262(a)10.100.1.24"
call-id="4070150262(a)10.100.1.24" local-tag="as7c372911"
remote-tag="3861741811" remote-uri="sip:252@10.100.1.24:5064"
local-uri="sip:254@10.100.1.85:6050" direction="initiator">
<note>On the phone</note>
<remote>
<identity display="user252">sip:252@10.100.1.85</identity>
<target uri="sip:252@10.100.1.85">
</target>
</remote>
<local>
<identity display="user254">sip:254@10.100.1.85</identity>
<target uri="sip:254@10.100.1.85"/>
</local>
<state>confirmed</state>
</dialog>
</dialog-info>
```
Next PUBLISH is with single dialog, and its update is ignored (as incorrect state
evaluated)
```
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info"
version="37" state="full" entity="252">
<dialog id="4070150262(a)10.100.1.24"
call-id="4070150262(a)10.100.1.24" local-tag="as7c372911"
remote-tag="3861741811" remote-uri="sip:252@10.100.1.24:5064"
local-uri="sip:254@10.100.1.85:6050" direction="initiator">
<note>Ready</note>
<remote>
<identity>252</identity>
<target uri="252">
</target>
</remote>
<local>
<identity>254</identity>
<target uri="254"/>
</local>
<state reason="local-bye">terminated</state>
</dialog>
</dialog-info>
```
### Possible Solutions
Sorry for the long story, but for now I need your advice, with the logic for the fix (I
already tried to start to fix, but get stuck with the logical concept).
My current insight is quite cumbersome:
- before is_dialog_terminated => get an array of dialogs call-ids from the body of
current PUBLISH. Give it as input parameter for is_dialog_terminated
- while processing get_dialog_state/parse_dialog_state_from_body = try to match state of
matched dialogs
- in some way try to update not complete body in a DB, but make some "partial"
update. (update only those dialogs whose old state is NOT "terminated")
Thanks in advance for your advice. If the issue unclear from my description, please ask
for details.
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
kamailio -v
version: kamailio 5.0.3 (i386/linux)
flags: STATS: Off, EXTRA_DEBUG, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE,
USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC,
DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER,
USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024,
BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 11:27:38 Jan 30 2018 with gcc 4.3.2
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427
5 Feb
5 Feb
5:49 p.m.
@phil-lavin , can you take a look at this thread?
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-363106217
12 Feb
12 Feb
12:18 p.m.
@vance-od - I tried a quick fix with the patches referenced above. Can you try with them
and see if all ok? It relies on matching all related dialog states in the same xml
document. If one found mismatching, then will not consider it terminated. Likely it can be
improved with matching on callid, but this can be a starting point.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-364866447
1:42 p.m.
Hi, Daniel! thanks for the patch!
will give it a try today
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-364885964
7:55 p.m.
I tried proposed changes.
in ps_match_dialog_state_from_body
there is a loop:
while(node != NULL) {
....
why do we need there one more while loop?
What actually happens:
.....
if(strcmp(tmp_state, vstate)!=0) { // here we come only once, when matching first dialog
...
all later dialogs are iterating in the second while loop.
as for me this part of code
```
+ do {
+ if(node->next != NULL && node->next->name != NULL
+ && xmlStrcmp(node->name, node->next->name) == 0) {
+ node = node->next;
+ break;
+ }
+ node = node->next;
+ } while(node != NULL);
```
should look like:
```
node = node->next;
```
maybe that checks for NULL are also necessary, but not while do-while.
General question - is there a way to propose changes in your custom branch?
thanks for your help!
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-364987310
13 Feb
13 Feb
10:21 a.m.
What was the result of testing it? Not working?
The `while()` is there to deal with xml docs that have many `dialog` nodes. The `do { ...
} while ()` is to find the next node with `dialog` name. These are to be compliant with
xml specs, as there can be other nodes with different names. So just doing
`node=node->next` doesn't ensure it will be the next `dialog` node, but the next
node in the xml document.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-365172882
10:55 a.m.
The result: for multiple dialog bodie only first body checked (I added custom logging
inside your code to see where it worked)
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-365178957
14 Feb
14 Feb
11:32 a.m.
re-tested it again, it does check only first dialog in a body
your code with my custom logging
```
int ps_match_dialog_state_from_body(str body, int *is_dialog, char *vstate)
{
xmlDocPtr doc;
xmlNodePtr node;
xmlNodePtr childNode;
char *tmp_state;
int rmatch = 0;
*is_dialog = 0;
LM_ERR("****** body to parse %s\n", body);
doc = xmlParseMemory(body.s, body.len);
if(doc == NULL || doc->children == NULL)
{
LM_ERR("failed to parse xml document\n");
return -1;
}
node = xmlNodeGetChildByName(doc->children, "dialog");
while(node != NULL)
{
*is_dialog = 1;
childNode = xmlNodeGetChildByName(node, "state");
tmp_state = (char *)xmlNodeGetContent(childNode);
if (tmp_state != NULL)
{
LM_ERR("vstate is %s, tmp_state is %s\n", vstate, tmp_state);
if(strcmp(tmp_state, vstate)!=0) {
LM_ERR("states are different! goto done \n");
xmlFree(tmp_state);
rmatch = 0;
goto done;
}
rmatch = 1;
xmlFree(tmp_state);
}
/* search for next dialog node */
do {
LM_ERR("do entered \n");
if(node->next != NULL && node->next->name != NULL
&& xmlStrcmp(node->name, node->next->name) == 0) {
node = node->next;
LM_ERR("break it \n");
break;
}
node = node->next;
LM_ERR("node->next \n");
} while(node != NULL);
}
done:
xmlFreeDoc(doc);
LM_ERR("going to return rmatch %d\n", rmatch);
return rmatch;
}
```
body of PUBLISH, that being processed:
```
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info"
version="109" state="full" entity="252">
<dialog id="3282208261(a)10.100.1.24"
call-id="3282208261(a)10.100.1.24" local-tag="as0cf4d423"
remote-tag="3673383467" remote-uri="sip:252@10.100.1.24:33035"
local-uri="sip:254@10.100.1.85:6050" direction="initiator">
<note>On the phone</note>
<remote>
<identity display="user252">sip:252@10.100.1.85</identity>
<target uri="sip:252@10.100.1.85">
</target>
</remote>
<local>
<identity display="user254">sip:254@10.100.1.85</identity>
<target uri="sip:254@10.100.1.85"/>
</local>
<state>confirmed</state>
</dialog>
</dialog-info>
```
logs printed by kamailio:
```
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:321]: ps_match_dialog_state_from_body(): ****** body to parse <?xml
version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info"
version="108" state="full" entity="252">
<dialog id="0b386c6122b2dabc0fa49b1d4972ca3c@127.0.0.1:6050"
call-id="0b386c6122b2dabc0fa49b1d4972ca3c@127.0.0.1:6050"
local-tag="as29381132" remote-tag="3958334712"
remote-uri="sip:252@10.100.1.24:33035"
local-uri="sip:251@127.0.0.1:6050" direction="recipient">
<note>Ready</note>
<remote>
<identity>252</identity>
<target uri="252">
</target>
</remote>
<local>
<identity>251</identity>
<target uri="251"/>
</local>
<state>terminated</state>
</dialog>
<dialog id="3282208261(a)10.100.1.24"
call-id="3282208261(a)10.100.1.24" local-tag="as0cf4d423"
remote-tag="3673383467" remote-uri="sip:252@10.100.1.24:33035"
local-uri="sip:254@10.100.1.85:6050" direction="initiator">
<note>On the phone</note>
<remote>
<identity display="user252">sip:252@10.100.1.85</identity>
<target uri="sip:252@10.100.1.85">
</target>
</remote>
<local>
<identity display="user254">sip:254@10.100.1.85</identity>
<target uri="sip:254@10.100.1.85"/>
</local>
<state>confirmed</state>
</dialog>
</dialog-info>
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:341]: ps_match_dialog_state_from_body(): vstate is terminated, tmp_state is
terminated
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:355]: ps_match_dialog_state_from_body(): do entered
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:363]: ps_match_dialog_state_from_body(): node->next
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:355]: ps_match_dialog_state_from_body(): do entered
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:363]: ps_match_dialog_state_from_body(): node->next
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:355]: ps_match_dialog_state_from_body(): do entered
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:363]: ps_match_dialog_state_from_body(): node->next
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:355]: ps_match_dialog_state_from_body(): do entered
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:363]: ps_match_dialog_state_from_body(): node->next
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:369]: ps_match_dialog_state_from_body(): going to return rmatch 1
Feb 14 09:25:48 0050562c117c /usr/sbin/kamailio[29343]: ERROR: presence
[presentity.c:559]: ps_match_dialog_state(): rmatch is 1
```
so for some reason in `do { ... } while ()` it did not break.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-365531427
15 Feb
15 Feb
1:01 p.m.
Can you print `node->name` and `node->next->name` inside the `do { } while()` to
see the names that are compared there?
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-365878809
5:24 p.m.
Hi, Daniel! Thank you for your help!
I tried to print that value in logs, but get stuck a bit (I did not found how to print xml
elements correctly). I got some sequence of crashes while attempts to add appropriate
logs.
What I tried more:
I changed:
` && xmlStrcmp(node->name, node->next->name) == 0) {
`
to
` && xmlStrcmp(node->next->name, (const xmlChar *)"dialog") ==
0) {
`
and now second dialog compare works, appropriate logs are (all is the same as in my latest
comment):
```
Feb 15 15:15:18 0050562c117c /usr/sbin/kamailio[8030]: ERROR: presence [presentity.c:361]:
ps_match_dialog_state_from_body(): vstate is terminated, tmp_state is terminated
Feb 15 15:15:18 0050562c117c /usr/sbin/kamailio[8030]: ERROR: presence [presentity.c:375]:
ps_match_dialog_state_from_body(): do entered
Feb 15 15:15:18 0050562c117c /usr/sbin/kamailio[8030]: ERROR: presence [presentity.c:389]:
ps_match_dialog_state_from_body(): node->next
Feb 15 15:15:18 0050562c117c /usr/sbin/kamailio[8030]: ERROR: presence [presentity.c:375]:
ps_match_dialog_state_from_body(): do entered
Feb 15 15:15:18 0050562c117c /usr/sbin/kamailio[8030]: ERROR: presence [presentity.c:385]:
ps_match_dialog_state_from_body(): break it
Feb 15 15:15:18 0050562c117c /usr/sbin/kamailio[8030]: ERROR: presence [presentity.c:361]:
ps_match_dialog_state_from_body(): vstate is terminated, tmp_state is confirmed
Feb 15 15:15:18 0050562c117c /usr/sbin/kamailio[8030]: ERROR: presence [presentity.c:364]:
ps_match_dialog_state_from_body(): states are different! goto done
Feb 15 15:15:18 0050562c117c /usr/sbin/kamailio[8030]: ERROR: presence [presentity.c:395]:
ps_match_dialog_state_from_body(): going to return rmatch 0
```
in my understanding of your proposed patch, we compare:
`node->name` - is always the name of current node
`node->next->name` - name of next node
such compare would match only if there are to consecutive "dialog" nodes. (and
that did not happen in my yesterday's tests).
Sorry if I'am writing/supposing something trivial or incorrect, I have never worked
before with libxml and XML from C code as well.
Thanks
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-365941679
7:57 p.m.
Put this do...while():
```
/* search for next dialog node */
do {
LM_ERR("do entered \n");
if(node->next != NULL && node->next->name != NULL
&& xmlStrcmp(node->name, node->next->name) == 0) {
node = node->next;
LM_ERR("break it \n");
break;
}
if(node->next != NULL && node->next->name != NULL) {
LM_ERR("compared [%s] with [%s]\n", node->name, node->next->name);
}
node = node->next;
LM_ERR("node->next \n");
} while(node != NULL);
```
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-365991818
16 Feb
16 Feb
10:58 a.m.
my shame... I did not do NULL check and that was the reason for crash.
With your logging added (processing same body and input PUBLISH as before):
```
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:361]: ps_match_dialog_state_from_body(): vstate is terminated, tmp_state is
terminated
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:388]: ps_match_dialog_state_from_body(): do entered
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:396]: ps_match_dialog_state_from_body(): compared [dialog] with [text]
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:399]: ps_match_dialog_state_from_body(): node->next
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:388]: ps_match_dialog_state_from_body(): do entered
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:396]: ps_match_dialog_state_from_body(): compared [text] with [dialog]
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:399]: ps_match_dialog_state_from_body(): node->next
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:388]: ps_match_dialog_state_from_body(): do entered
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:396]: ps_match_dialog_state_from_body(): compared [dialog] with [text]
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:399]: ps_match_dialog_state_from_body(): node->next
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:388]: ps_match_dialog_state_from_body(): do entered
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:399]: ps_match_dialog_state_from_body(): node->next
Feb 16 08:54:16 0050562c117c /usr/sbin/kamailio[30264]: ERROR: presence
[presentity.c:406]: ps_match_dialog_state_from_body(): going to return rmatch 1
```
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-366167097
11:08 a.m.
I just pushed patch 29d09b38fab5a1ee8d7f6f82818e3d3446d4dd8b for it.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-366168714
12:06 p.m.
thanks for the last patch, I tried it.
Making the fast check the match of multiple dialog body works as expected.
Let me do deeper testing today. Will report results later.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-366179888
19 Feb
19 Feb
12:26 p.m.
Closed #1427.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#event-1480150056
12:26 p.m.
Thanks, reopen (if related) or create a new item (if different) when something wrong pops
up.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-366631994
1:21 p.m.
Hi, Daniel!
I did more testing and provided change works.
What do you think regarding proper solution with comparing call-id (as you mentioned in
the beginning)?
Because current change improve the situation, but it is not what is expected by RFC.
Anyway - I think this changes should be committed.
Regarding the following work, should we create another task, or leave this thread open?
(I have plans to work on the task following weeks, and possibly will need advice/review)
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-366646317
1:30 p.m.
My work was to get it at least work as before of 839cf89. I do not have time for any
further work, so anyone else willing to do it is more than welcome.
You can open a PR when you start the work and ask for review/suggestions if you get
stuck.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1427#issuecomment-366648433
2470
days inactive
2484
days old
17 comments
2 participants
participants (2)
-
Daniel-Constantin Mierla -
Vasiliy Ganchev