[OpenSIPS-Devel] [opensips] Proposed fix for erratic nat_traversal keepalives (#751)

Tue Jan 12 19:30:38 CET 2016

Saúl,

I see that each process registers a timer.  I would expect to see that the
timer would fire in each process once per interval.  What I see is that
once per second the timer callback to keepalive_timer is called on just one
process at a time.  A second later it's called on another process.

You can see this pattern in the trace below (I added trace at the end of
the keepalive_timer method showing the value of 'iteration').  There was a
single client registered, receiving keepalives.

My change ensures that each process observes the same counter, so the
workload is distributed across all processes.

Your solution, to revert to a dedicated timer process would definitely
solve the problem, as long as a single process (with a static iteration
variable) delivered the keepalives.

Thanks for looking into it!

Alan

====================================================================================================
Jan  6 18:56:16 alan-vm osips[28713]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 1
Jan  6 18:56:17 alan-vm osips[28719]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 2
Jan  6 18:56:18 alan-vm osips[28715]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:19 alan-vm osips[28717]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 1
Jan  6 18:56:20 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 0
Jan  6 18:56:21 alan-vm osips[28712]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:56:22 alan-vm osips[28722]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:23 alan-vm osips[28719]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:24 alan-vm osips[28724]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:25 alan-vm osips[28723]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:26 alan-vm osips[28711]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:27 alan-vm osips[28715]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:56:29 alan-vm osips[28717]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 2
Jan  6 18:56:30 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 1
Jan  6 18:56:31 alan-vm osips[28723]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:56:32 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 2
Jan  6 18:56:33 alan-vm osips[28722]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:56:34 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> send_keepalive
Jan  6 18:56:34 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 8
Jan  6 18:56:35 alan-vm osips[28718]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 1
Jan  6 18:56:36 alan-vm osips[28716]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:37 alan-vm osips[28713]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 2
Jan  6 18:56:38 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:39 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:56:40 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> send_keepalive
Jan  6 18:56:40 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 9
Jan  6 18:56:41 alan-vm osips[28713]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:42 alan-vm osips[28712]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 5
Jan  6 18:56:44 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 5
Jan  6 18:56:45 alan-vm osips[28717]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:56:46 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 6
Jan  6 18:56:47 alan-vm osips[28724]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:56:48 alan-vm osips[28713]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:56:49 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 0
Jan  6 18:56:50 alan-vm osips[28718]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 2
Jan  6 18:56:51 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 1
Jan  6 18:56:52 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 7
Jan  6 18:56:53 alan-vm osips[28719]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:56:54 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> send_keepalive
Jan  6 18:56:54 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 8
Jan  6 18:56:55 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> send_keepalive
Jan  6 18:56:55 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 9
Jan  6 18:56:56 alan-vm osips[28716]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:56:57 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 0
Jan  6 18:56:58 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 1
Jan  6 18:57:00 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 2
Jan  6 18:57:01 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:57:02 alan-vm osips[28724]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 5
Jan  6 18:57:03 alan-vm osips[28713]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 5
Jan  6 18:57:04 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:57:05 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 5
Jan  6 18:57:06 alan-vm osips[28721]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 6
Jan  6 18:57:07 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 2
Jan  6 18:57:08 alan-vm osips[28723]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 5
Jan  6 18:57:09 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:57:10 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 4
Jan  6 18:57:11 alan-vm osips[28713]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 6
Jan  6 18:57:12 alan-vm osips[28718]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 3
Jan  6 18:57:13 alan-vm osips[28720]: INFO:nat_traversal:keepalive_timer:
==> keepalive_timer 5

On Tue, Jan 12, 2016 at 3:14 AM, Saúl Ibarra Corretgé <
notifications at github.com> wrote:

> Hi, thanks for the patch! Can you please elaborate / link some
> documentation on why this is needed? According to the development guide
> <http://www.opensips.org/Documentation/Development-Manual#toc23>
> register_timer works on some "global timer process" which doesn't appear
> to be the case anymore.
>
> I see that the problem was introduced in caabbe5
> <https://github.com/OpenSIPS/opensips/commit/caabbe53229bde6c1d939da2e5380e805b94b983>.
> If timers are ran on all processes now, the change to nat_traversal is
> incorrect, because we depend on global data, so I'd rather revert back to
> using a dedicated timer process for our purposes, as before.
>
> @bogdan-iancu <https://github.com/bogdan-iancu> can you please shed some
> light here?
>
> —
> Reply to this email directly or view it on GitHub
> <https://github.com/OpenSIPS/opensips/pull/751#issuecomment-170879130>.
>

---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/pull/751#issuecomment-171003796
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/devel/attachments/20160112/36a5a2f6/attachment-0001.htm>