[kamailio/kamailio] TOPOS/REDIS : returning unexpected 481 not found after 4 minutes (#1848)
11 Feb
2019
11 Feb
'19
6:06 p.m.
### Description
BYE requests received after 4 minutes are failing with 481
### Troubleshooting
#### Reproduction
<!--
If the issue can be reproduced, describe how it can be done.
-->
#### Debugging Data
Seems like REDIS is set to expire the leg infomartion after 3 minutes.
Not sure where / why this is the case.
```
T 2019/02/11 16:49:55.818935 137.54.60.160:58580 -> 137.54.2.161:6379 [AP]
*3..$6..EXPIRE..$26..d:z:atpsh-5c3d1562-16-cf25..$5..10800..
#
T 2019/02/11 16:50:21.325761 137.54.60.160:58580 -> 137.54.2.161:6379 [AP]
*3..$6..EXPIRE..$26..d:z:atpsh-5c3d1562-16-df25..$5..10800..
#
T 2019/02/11 16:50:26.582118 137.54.60.160:58574 -> 137.54.2.161:6379 [AP]
*3..$6..EXPIRE..$26..d:z:atpsh-5c3d1562-16-df25..$3..180..
#
T 2019/02/11 16:50:43.299621 137.54.60.160:58574 -> 137.54.2.161:6379 [AP]
*3..$6..EXPIRE..$26..d:z:atpsh-5c3d1562-16-df25..$3..180..
#
```
I will troubleshoot this further.
--
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/1848
11 Feb
11 Feb
6:52 p.m.
https://lists.kamailio.org/pipermail/sr-users/2018-March/100835.html
--
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/1848#issuecomment-462426289
9:59 p.m.
Do you get the same error messages as in the linked mailing list 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/1848#issuecomment-462492003
11:49 p.m.
@jchavanton - the expires of 180 is set on dialog key when the BYE is processed.
Can you reproduce the case? Can you look at the sip traffic?
What is your kamailio version?
--
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/1848#issuecomment-462526430
12 Feb
12 Feb
12:31 a.m.
Thanks for the hint about the BYE/EXPIRE 180s, good to know about this expected behavior.
I will get back with more debugging information/messages when I can grab them.
The version I am using in this case is a little bit forked , I did look and but the module
TOPOS and TOPOS_REDIS are the same as latest master.
Hope to gather more information soon.
--
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/1848#issuecomment-462538559
5:20 p.m.
```
Feb 12 16:18:33 localhost 11f127b633b3[15693]: 2(18) NOTICE: <script>:
[MAIN][INVITE][2017998478_92254488(a)74.120.93.200] from[+12063889971] to[+12012673277]
Feb 12 16:18:33 localhost 11f127b633b3[15693]: 2(18) NOTICE: topos_redis
[topos_redis_storage.c:282]: tps_redis_insert_dialog(): expire[10800] set on dialog record
for [d:z:atpsh-5c62f0e3-12-1] with argc 3
Feb 12 16:18:33 localhost 11f127b633b3[15693]: 2(18) NOTICE: topos_redis
[topos_redis_storage.c:521]: tps_redis_insert_branch(): expire[180] set on branch record
for [b:x:z9hG4bK8af2.ac26ccca5d972377f16448477a62b3e2.0] with argc 3
Feb 12 16:18:33 localhost 11f127b633b3[15693]: 16(32) NOTICE: <script>:
[MAIN_REPLY][100][2017998478_92254488(a)74.120.93.200]
Feb 12 16:18:33 localhost 11f127b633b3[15693]: 16(32) NOTICE: <script>:
[MAIN_REPLY][180][2017998478_92254488(a)74.120.93.200]
```
On my test server/config
The second expire is also triggered when receiving the initial invite
--
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/1848#issuecomment-462825958
5:24 p.m.
I guess in tps_redis_insert_branch() we should use the dialog expire time, since it is
needed to handle in-dialog messages.
But then, others would have noticed by now.
--
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/1848#issuecomment-462828027
5:27 p.m.
Maybe the regression is in this commit
```
commit e712d32f9304f95b5b19b26905546b4af700298f
Author: Daniel-Constantin Mierla <miconda(a)gmail.com>
Date: Thu Mar 2 16:40:41 2017 +0100
topos_redis: update fields and reduce expires for termintated dialogs
diff --git a/src/modules/topos_redis/topos_redis_storage.c
b/src/modules/topos_redis/topos_redis_storage.c
index 08ead91..100e823 100644
--- a/src/modules/topos_redis/topos_redis_storage.c
+++ b/src/modules/topos_redis/topos_redis_storage.c
@@ -267,7 +267,7 @@ int tps_redis_insert_dialog(tps_data_t *td)
rrpl = _tps_redis_api.exec_argv(rsrv, argc, (const char **)argv, argvlen);
if(rrpl==NULL) {
- LM_ERR("failed to execute expireredis command\n");
+ LM_ERR("failed to execute expire redis command\n");
if(rsrv->ctxRedis->err) {
LM_ERR("redis error: %s\n",
rsrv->ctxRedis->errstr);
}
@@ -386,7 +386,7 @@ int tps_redis_insert_branch(tps_data_t *td)
argvlen[argc] = rkey.len;
argc++;
- lval = (unsigned long)_tps_api.get_dialog_expire();
+ lval = (unsigned long)_tps_api.get_branch_expire();
if(lval==0) {
return 0;
}
```
--
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/1848#issuecomment-462829275
5:30 p.m.
Yes seems like the intent was "reduce expires for terminated dialogs" and this
is initial insert.
I will test the modification
--
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/1848#issuecomment-462830454
6:16 p.m.
strange both `tps_redis_insert_invite_branch` and `tps_redis_insert_branch` where expiring
the call leg information ...
tested with this patch and it is working fine ... I will paste more logs of the last
test.
https://github.com/kamailio/kamailio/pull/1849
--
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/1848#issuecomment-462848934
6:21 p.m.
Sorry, this patch is not enough, my test failed in the end .
Something else seems unexpected, `tps_redis_end_dialog` is called on the reception of the
ACK, not the BYE.
```
Feb 12 17:04:40 [15693]: 4(23) NOTICE: <script>:
[MAIN][INVITE][845153977_116759869123] from[+12063389971] to[+12013673277]
Feb 12 17:04:40 [15693]: 4(23) NOTICE: topos_redis [topos_redis_storage.c:282]:
tps_redis_insert_dialog(): expire[10800] set on dialog record for
[d:z:atpsh-5c62fc9a-17-1] with argc 3
Feb 12 17:04:40 [15693]: 4(23) NOTICE: topos_redis [topos_redis_storage.c:521]:
tps_redis_insert_branch(): expire[10800] set on branch record for
[b:x:z9hG4bKeff7.3c177f0a8f8f8c3bac4a8895164a6cc4.0] with argc 3
Feb 12 17:04:40 [15693]: 13(32) NOTICE: <script>:
[MAIN_REPLY][100][845153977_116759869123]
Feb 12 17:04:40 [15693]: 13(32) NOTICE: topos_redis [topos_redis_storage.c:393]:
tps_redis_insert_invite_branch(): expire[10800] set on branch record for
[b:x:INVITE:845153977_116759869123:eX.x-jGaUpMKHWbyYAb-NpuBVO9iQJjQ] with argc 3
Feb 12 17:04:40 [15693]: 13(32) NOTICE: <script>:
[MAIN_REPLY][180][845153977_116759869123]
Feb 12 17:04:40 [15693]: 13(32) NOTICE: topos_redis [topos_redis_storage.c:393]:
tps_redis_insert_invite_branch(): expire[10800] set on branch record for
[b:x:INVITE:845153977_116759869123:eX.x-jGaUpMKHWbyYAb-NpuBVO9iQJjQ] with argc 3
Feb 12 17:04:45 [15693]: 13(32) NOTICE: <script>:
[MAIN_REPLY][200][845153977_116759869123]
Feb 12 17:04:45 [15693]: 1(20) NOTICE: <script>:
[MAIN][ACK][845153977_116759869123] from[+12063389971] to[+12013673277]
Feb 12 17:04:45 [15693]: 1(20) NOTICE: topos_redis [topos_redis_storage.c:521]:
tps_redis_insert_branch(): expire[10800] set on branch record for
[b:x:z9hG4bKeff7.7e29bc1bbf5aa3b6de562e08981be91e.0] with argc 3
Feb 12 17:04:45 [15693]: 1(20) NOTICE: topos_redis [topos_redis_storage.c:1417]:
tps_redis_end_dialog(): expire[180] set on branch record for [d:z:atpsh-5c62fc9a-17-1]
with argc 3
```
--
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/1848#issuecomment-462851076
6:42 p.m.
I found the this code modification was fixing this problem, with ending the dialog when
receiving ACK,
there is probably an explanation I do not understand behind all of this, I guess I can
propose the modifications that are working for my test and we can clarify more details by
doing a review.
```
--- a/src/modules/topos/tps_msg.c
+++ b/src/modules/topos/tps_msg.c
@@ -1003,7 +1003,8 @@ int tps_request_sent(sip_msg_t *msg, int dialog, int local)
}
if(dialog!=0) {
- tps_storage_end_dialog(msg, &mtsd, ptsd);
+ if(get_cseq(msg)->method_id==METHOD_BYE)
+ tps_storage_end_dialog(msg, &mtsd, ptsd);
if(tps_storage_update_dialog(msg, &mtsd, &stsd,
TPS_DBU_CONTACT)<0) {
goto error;
}
```
--
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/1848#issuecomment-462859397
6:47 p.m.
logs of a working test, for reference :
```
>> INVITE/100/180/200
Feb 12 17:34:24
[15693]: 2(19) NOTICE: <script>: [MAIN][INVITE][2102176242_132063740]
from[+12062889971] to[+12013673277]
Feb 12 17:34:24 [15693]: 2(19) NOTICE: topos_redis [topos_redis_storage.c:282]:
tps_redis_insert_dialog(): expire[10800] set on dialog record for
[d:z:atpsh-5c630359-13-1] with argc 3
Feb 12 17:34:24 [15693]: 2(19) NOTICE: topos_redis [topos_redis_storage.c:521]:
tps_redis_insert_branch(): expire[10800] set on branch record for
[b:x:z9hG4bKf6fe.007fdabc1bdc2f8ace042caf65261193.0] with argc 3
Feb 12 17:34:24 [15693]: 15(32) NOTICE: <script>:
[MAIN_REPLY][100][2102176242_132063740]
Feb 12 17:34:24 [15693]: 15(32) NOTICE: topos_redis [topos_redis_storage.c:393]:
tps_redis_insert_invite_branch(): expire[10800] set on branch record for
[b:x:INVITE:2102176242_132063740:SYupS8vJMyhwTkUwf3A5JPOrtsnd-CM9] with argc 3
Feb 12 17:34:24 [15693]: 15(32) NOTICE: <script>:
[MAIN_REPLY][180][2102176242_132063740]
Feb 12 17:34:24 [15693]: 15(32) NOTICE: topos_redis [topos_redis_storage.c:393]:
tps_redis_insert_invite_branch(): expire[10800] set on branch record for
[b:x:INVITE:2102176242_132063740:SYupS8vJMyhwTkUwf3A5JPOrtsnd-CM9] with argc 3
Feb 12 17:34:29 [15693]: 15(32) NOTICE: <script>:
[MAIN_REPLY][200][2102176242_132063740]
>> ACK
Feb 12 17:34:29 [15693]: 3(20)
NOTICE: <script>: [MAIN][ACK][2102176242_132063740] from[+12062889971]
to[+12013673277]
Feb 12 17:34:29 [15693]: 3(20) NOTICE: topos_redis [topos_redis_storage.c:521]:
tps_redis_insert_branch(): expire[10800] set on branch record for
[b:x:z9hG4bKf6fe.6226db2bc5ec24aa36590d6663245093.0] with argc 3
>> BYE/200 OK
Feb 12 17:38:39 [15693]:
15(32) NOTICE: <script>: [MAIN][BYE][2102176242_132063740] from[+12013673277]
to[+12062889971]
Feb 12 17:38:39 [15693]: 15(32) NOTICE: topos_redis [topos_redis_storage.c:521]:
tps_redis_insert_branch(): expire[10800] set on branch record for
[b:x:z9hG4bK7955.6e872259f2d6a5d0c981ea20a55a88d7.0] with argc 3
Feb 12 17:38:39 [15693]: 15(32) NOTICE: topos_redis [topos_redis_storage.c:1417]:
tps_redis_end_dialog(): expire[180] set on branch record for [d:z:atpsh-5c630359-13-1]
with argc 3
Feb 12 17:38:40 [15693]: 4(21) NOTICE: <script>:
[MAIN_REPLY][200][2102176242_132063740]
```
--
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/1848#issuecomment-462861534
13 Feb
13 Feb
7:16 p.m.
Closed #1848.
--
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/1848#event-2137530583
7:16 p.m.
This issue does not exist on the latest master branch.
--
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/1848#issuecomment-463307777
2118
days inactive
2120
days old
14 comments
3 participants
participants (3)
-
Daniel-Constantin Mierla -
Henning Westerholt
-
Julien Chavanton