[kamailio/kamailio] TOPOS/REDIS : returning unexpected 481 not found after 4 minutes (#1848)

List overview All Threads
Download

newer

older

git:master:a3dca980:...

[kamailio/kamailio] topos_redis:...

Julien Chavanton

11 Feb 2019 11 Feb '19

5:06 p.m.

### Description

BYE requests received after 4 minutes are failing with 481

### Troubleshooting

#### Reproduction

#### 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

Attachments:

attachment.html (text/html — 2.6 KB)

Show replies by date

Julien Chavanton

11 Feb 11 Feb

5: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

Henning Westerholt

8: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

Daniel-Constantin Mierla

10: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

Julien Chavanton

11:31 p.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

Julien Chavanton

12 Feb 12 Feb

4:20 p.m.

``` Feb 12 16:18:33 localhost 11f127b633b3[15693]: 2(18) NOTICE: <script>: [MAIN][INVITE][2017998478_92254488@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@74.120.93.200] Feb 12 16:18:33 localhost 11f127b633b3[15693]: 16(32) NOTICE: <script>: [MAIN_REPLY][180][2017998478_92254488@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

Julien Chavanton

4: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

Julien Chavanton

4:27 p.m.

Maybe the regression is in this commit

``` commit e712d32f9304f95b5b19b26905546b4af700298f Author: Daniel-Constantin Mierla miconda@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

Julien Chavanton

4: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

Julien Chavanton

5: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

Julien Chavanton

5: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

Julien Chavanton

5: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

Julien Chavanton

5: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

Julien Chavanton

13 Feb 13 Feb

6: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

Julien Chavanton

6: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

2266

Age (days ago)

2268

Last active (days ago)

sr-dev@lists.kamailio.org

14 comments

3 participants

tags (0)

participants (3)

Daniel-Constantin Mierla
Henning Westerholt
Julien Chavanton