Re: "clone" syscall in keepalived healthchecking child takes more time after switching

Please note, we plan to opensource the scripts used on top of Keepalived.

Not sure if this will be in official OVH github repo or somewhere else.

It seems only fair to give a little back to the community, given the 
amount of opensource code we use :)

Regards,


On 2017-10-01 10:00 AM, Quentin Armitage wrote:
> On Thu, 2017-09-28 at 16:02 -0400, Damien Clabaut wrote:
>> Hello Keepalived devs,
>>
>> While testing Keepalived version 1.3.6 on Debian8, I came accross a
>> strange issue.
>>
>> Tl;DR: It seems that after every vrrp state change, the "clone" system
>> call takes a little more time, slowly eating up all CPU.
>>
>> Details:
>>
>> I start keepalived with 200 instances (100 IPv4 + 100 IPv6).
>> Each instance tracks a different script.
>> The keepalived healthcheck children (as described on
>> http://keepalived.org/documentation.html) has PID 177548:
>>
>> [root@bz-perflab-6-vr /home/dclabaut/mac_flap] echo $(($(cat
>> /var/run/keepalived.pid) + 2))
>> 177458
>>
>> All instances are in the MASTER state on this machine. Strace -c gives
>> me the count of system calls on a 60 second time period:
>>
>> [root@bz-perflab-6-vr /home/dclabaut/mac_flap] timeout 60 strace -cp 177458
>> % time     seconds  usecs/call     calls    errors syscall
>> ------ ----------- ----------- --------- --------- ----------------
>>    84.96    2.676412         880      3041       689 clone
>>
>> Using vrrp_scripts, I move all instances to BACKUP state, then back to
>> MASTER state, and run the same command
>>
>> [root@bz-perflab-6-vr /home/dclabaut/mac_flap] timeout 60 strace -cp 177458
>> % time     seconds  usecs/call     calls    errors syscall
>> ------ ----------- ----------- --------- --------- ----------------
>>    97.85   15.866534        4887      3247       901 clone
>>
>>
>> Again, I move all instances to BACKUP then MASTER, and take a trace.
>>
>> There are about the same number of "clone" syscalls, but now they take
>> 8651 usecs/call
>>
>> To make sure this a consequence of state change, I wait 10 then 20
>> minutes and take new traces.
>>
>> There is still the same number of "clone" syscalls, and now they take
>> 7440 usecs/call.
>>
>> On a separate experiment where I kept changing the VRRP state, I saw an
>> entire core being used by this process.
>>
>> Is this a known issue?
>>
>> What can I do to help fix it?
>>
>> Kind regards,
>>
> Hi Damian,
>
> This sounds an interesting problem. In the first place could you please
> provide a copy of your configuration files (presumably from at least
> two system  as close as possible to what you are running, and also
> copies of the scripts. I'll then see if I can reproduce the problem in
> a Debian VM, and if so see if other distros exhibit the same problem.
> I'll also have a look so see if my latest development version, which
> has quite a few changes in the way scripts are run, also exhibits the
> same problem.
>
> It would be helpful if you could explain what you do to force all the
> instances into backup and then back to master, and over what timescale.
>
> At the moment I haven't a clue what the problem might be.
>
> Could you write a program that could issue a few hundred clone() system
> calls, and see what happens to the performance of those around the time
> you see the different results for keepalived?
>
> BTW, echo $(($(cat /var/run/keepalived.pid) + 2)) isn't a reliable way
> of getting the pid of the keepalived_vrrp process. I sometimes see the
> keepalived parent and children processes having consecutive pids, and
> sometimes there are gaps of one or two in between. Better to use
> vrrp.pid.
>
> Many thanks for reporting this issue.
>
> Quentin Armitage

-- 
Damien Clabaut
R&D vRouter
ovh.qc.ca


------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot