uac_registrant and external "expires" parameter (in 200OK)

[achalkov]

Situation:
A = registrant (our opensips with uac_registrant module). all REGISTERS sent with expires=600 (as ct.fields(expires))

B = registrar (some sip-server). Sends 200OK with expires=120 (as ct.fields(expires) or header "expires") to REGISTERs with expires greater then 120.

When A receives 200OK with expires=120 from B, it does not modify expiration of registration and sends sequential REGISTERs after ~600 seconds.

[ovidiusas]

Please provide a trace for it and the version of opensips that you are using.

[achalkov]

opensips 1.10 latest git commit as registrant.
i sent pcap trace to your email

[bogdan-iancu]

Hi @ovidiusas , any progress with this bug ?

[ovidiusas]

I will try to work on it tomorrow.

[ovidiusas]

This is working fine on dev and 1.11.
I will try to reproduce it on 1.10 ...

[ovidiusas]

There are no differences between 1.10 and dev.
@achalkov please post your version of opensips here.

[nikbyte]

One of latest 1.10 from git (92d6ed4).

[ovidiusas]

Please post the uac_registrant params and the output of 'opensips -V'

[ovidiusas]

A similar issue was fixed a while ago:
commit f9a8d98
Author: Ovidiu Sas osas@voipembedded.com
Date: Fri Nov 22 12:34:03 2013 -0500

uac_registrant: re-register with expires value imposed by the registrar

[nikbyte]

version: opensips 1.10.1-tls (x86_64/linux)
flags: STATS: On, USE_IPV6, USE_TCP, USE_TLS, DISABLE_NAGLE, USE_MCAST, SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
@(#) $Id$
main.c compiled on 21:27:03 May 5 2014 with gcc 4.4.7

loadmodule "uac_registrant.so"
modparam("uac_registrant", "hash_size", 5)
modparam("uac_registrant", "timer_interval", 60)
modparam("uac_registrant", "db_url", "")

[nikbyte]

The issue was fixed Nov 22. However, we use latest git 1.10.

[ovidiusas]

Something is not right with your install: I don't see the git version on the output of 'opensips -V'.

See the output that I have:

version: opensips 1.10.1-notls (x86_64/linux)
flags: STATS: On, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
git revision: 0702576
@(#) $Id$
main.c compiled on 13:24:47 May 6 2014 with gcc 4.4.7

[nikbyte]

You may be sure we use git.

rpm -qa|grep opensips-1

opensips-1.10.1.20140505.92d6ed4-2.x86_64

[achalkov]

any progress in this task?
or you need some additional information?

[ovidiusas]

This issue was fixed a while ago (see my previous comments).
You need to build from the latest stable and re-test.

I know that you are claiming that you are building from latest git, but your output for 'opensips -V' doesn't show the git version which is odd ...

You can try to register from a test box running 1.11 (it's the same codebase for uac_registrant).
My tests are showing that the code works ok.

Regards,
Ovidiu Sas

[achalkov]

we have latest stable version from git. now updated to 1.11 and problem is still there

[ovidiusas]

Please provide me with the output of 'opensips -V'.

[achalkov]

version: opensips 1.11.1-tls (x86_64/linux)
flags: STATS: On, USE_IPV6, USE_TCP, USE_TLS, DISABLE_NAGLE, USE_MCAST, SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
main.c compiled on 13:24:44 May 14 2014 with gcc 4.4.7

[ovidiusas]

You mentioned that you are compiling from git. I don't see your git version in the output of 'opensips -V'.

I will need an account on your server and I will try to register to it to reproduce it.
In the mean time, there's nothing I can do since it's working ok for me.

[nikbyte]

Ovidiu, when you build rpm or compile opensips manually, "opensip -V" doesn't write git version (I'll figure out how to fix this). But you may be sure we use git. Today we change 1.10 into 1.11. The same problem. And sorry, we cannot give you access. We can give you any information you need and we can install your patches to get debug info or test.

[ovidiusas]

Nick,

I build my own rpms from git and it always has the git revision in it.
I tested the scenario that you provided to me and I pointed out to you that this issue was fixed.
All I need is an account on your server to perform a registration, but it seems that this is not possible.
The pcap trace that you sent me has a different useragent then opensips (and therefor I don't know if it's really opensips that is performing the registration).

For all the above reasons, I don't really thing that this is a real issue (it was already fixed, from my POV) and I can't spend more time on it.
As a workaround for your setup, set the registration time to match the registrar's timeout and things should work ok.

Regards,
Ovidiu Sas

[nikbyte]

I double checked, my own rpms and daily rpms from yum.opensips.org doesn't have git release. I'll fix it, but now they have not. You're really incredulous man. :-) Yes, our opensips have different useragent, but it's really opensips, it's really built from git. :-) Maybe logs with debug=4 can help you or something else? We can change useragent back, if you wish. :-) We can add your debug patch, which will show us how it processed expires...

P.S. We cannot set registration time as on one registrar because we send many registrations to many servers.

[nikbyte]

I've found the error. It's not on your side. We changed contact in local route, then contact->uri != rec->contact_uri and module didn't use expires from contact. We will try to avoid contact changing in local route. But I've found logical problem in code. You divide timer_interval on reg_hsize when initializing timer, but you don't divide timer_interval when you calculate expiration time. So, with hash_size=4 (16) and timer_interval=80, timer starts every 5 seconds, but for expire=120 we will update every 60 seconds. Greater than timer_interval, the less update time.
Please, look into my patch, fixing this. #234

[nikbyte]

Recreated pull request. The proper one: #236

[ovidiusas]

Both hash size and timer interval are configurable so the admin can tune them to fit their needs.
One reason for having a hash is to avoid running over all records when the timer fires.
When the timer fires, the modules checks only one entry into the hash table, that's why the timer_interval is divided by reg_hsize during initialization.

If you want to use expire=120 with a hash_size =4, then set:
modparam("uac_registrant", "timer_interval", 32)
modparam("uac_registrant", "hash_size", 4)

This will result in 16 branches in the hash table. Each record will be checked every 32s and every 2s the timer will fire checking one branch in the hash table.

[nikbyte]

I think this moment not well documented.

And also something wrong there.
If I have timer_interval 60 with hash_size 5 then for registration with expires=120 we have
rec->registration_timeout = now + 120 - 60 = now + 60
So, we will update every 60 seconds. It's not good.

Maybe this logic will be better?
rec->registration_timeout = now + 120 - 120*0.8 (80% of expires)

rec->registration_timeout = now + rec->expires - rec->expires*0.8;
instead of
rec->registration_timeout = now + rec->expires - timer_interval;

When you have many registrants and database with many different intervals, you will have many inaccuracies with re-register intervals.

Or we should better document this moment. For example, we should recommend using as small timer_interval as user can.

[ovidiusas]

I pushed some changes into trunk (some extra checks and more error logs).
Please give it a try and report back any issues.

[ovidiusas]

Documentation updated.