Skip to Content.
Sympa Menu

rare-dev - Re: [rare-dev] bf_fwd issues

Subject: Rare project developers

List archive

Re: [rare-dev] bf_fwd issues


Chronological Thread 
    < Chronological >      < Thread >
  • From: mc36 <>
  • To: "" <>, Alexander Gall <>
  • Cc: Vágó Tibor <>, Frédéric LOUI <>
  • Subject: Re: [rare-dev] bf_fwd issues
  • Date: Fri, 6 May 2022 10:41:48 +0200
okkk,
with these changes we got the profiler functionality:
https://github.com/rare-freertr/freeRtr/commit/128c4b08055fc9a62d4196e2e1956d334efc2950
https://github.com/rare-freertr/freeRtr/commit/3bcf10d0785cb2069ca97a84f0f5696681889b6c
alex, we'll need https://packages.debian.org/search?keywords=python3-yappi
br,
cs


On 5/5/22 23:04, mc36 wrote:
hi,
as you maybe already know, we're piloting to the 4k mpls lns use case
heavily...
at this point rare had no issues picking up them, and performing the
forwarding,
but today we performed some stress tests on the setup, especially flapping the
cpes heavily, and we realized that this setup completely ruined the cpe
connectivity.
the bgp-lu with the lns came up as expected but the cpes had forwarding
issues...
after a bit later, even the interface counters frozen on the lns... at this
point
i unbinded the l2tp server from the vrf basically stopping the flap and the
box
slowly stabilized... finally those who were in, successfully brought up the
bgp-vpns
session through the lns... but it took a hour or so... :) looking at top
showed quickly
the bottleneck, bf_fwd ate 100% whereas bffwd was around 15% and i saw
nothing in the
"debug server p4 tx".. so here is my idea: some unknown series of events
rendered bffwd
to process the updates extremely slow... below you can see on (1), it was
barely able
to process 1.5mb of updates in 10 minutes... this box also holds about ~5000
v4/v6 routes
from the nren core, and sending those after a killall -9 python3 took some
seconds (2)....
so we need a tool to be have some insight in such a case... java have
visualvm which can
attached any time, but, is there such a tool for python?
thanks,
cs



1)

mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:10:21 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1920400 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (5.96/0/0)
tcp 72704 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:10:30 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1920801 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (6.43/0/0)
tcp 56320 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:10:40 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1921503 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (10.18/0/0)
tcp 39936 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:11:37 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1835248 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (8.96/0/0)
tcp 48640 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:11:52 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1836080 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (21.43/0/0)
tcp 24064 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:12:03 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1837105 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (10.57/0/0)
tcp 7680 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:12:11 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1743543 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (1.57/0/0)
tcp 85760 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:12:25 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1744323 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (11.84/0/0)
tcp 69376 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:12:30 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1744557 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (7.65/0/0)
tcp 61184 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:12:35 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1744880 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (2.15/0/0)
tcp 52992 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:12:40 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1745270 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (25.60/0/0)
tcp 44800 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:13:16 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1651566 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (2.36/0/0)
tcp 71552 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:13:38 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1652877 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (2.26/0/0)
tcp 30592 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:14:10 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1589068 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (13.92/0/0)
tcp 40960 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:14:29 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1524427 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (0.10/0/1)
tcp 65536 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:16:34 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1269061 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (19.48/0/0)
tcp 32768 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:16:37 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1269139 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (17.27/0/0)
tcp 32768 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:18:47 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1144975 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (0.00/0/0)
tcp 65536 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:18:56 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 1146015 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (11.47/0/0)
tcp 57344 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:20:07 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 822112 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (21.13/0/0)
tcp 16384 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:22:28 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 699144 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (25.84/0/0)
tcp 49152 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:23:11 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 701974 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (50.42/0/0)
tcp 16384 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:23:20 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 702416 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (42.17/0/0)
tcp 8192 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:24:11 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 0 640360 127.0.0.1:9080 127.0.0.1:48386
ESTABLISHED probe (11.81/0/0)
tcp 32768 0 127.0.0.1:48386 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
mc36@stordis:~$




2)

mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:57:16 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 19200 0 127.0.0.1:48416 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
tcp 0 181366 127.0.0.1:9080 127.0.0.1:48416
ESTABLISHED probe (0.52/0/0)
tcp 0 0 127.0.0.1:48386
127.0.0.1:9080 TIME_WAIT timewait (42.11/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:57:17 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 2816 0 127.0.0.1:48416 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
tcp 0 181418 127.0.0.1:9080 127.0.0.1:48416
ESTABLISHED probe (2.90/0/0)
tcp 0 0 127.0.0.1:48386
127.0.0.1:9080 TIME_WAIT timewait (41.00/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:57:18 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 71040 0 127.0.0.1:48416 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
tcp 0 85854 127.0.0.1:9080 127.0.0.1:48416
ESTABLISHED probe (0.11/0/0)
tcp 0 0 127.0.0.1:48386
127.0.0.1:9080 TIME_WAIT timewait (39.94/0/0)
mc36@stordis:~$ date ; netstat -ano | grep 9080
Thu 05 May 2022 10:57:20 PM CEST
tcp 0 0 0.0.0.0:9080 0.0.0.0:*
LISTEN off (0.00/0/0)
tcp 38272 0 127.0.0.1:48416 127.0.0.1:9080
ESTABLISHED off (0.00/0/0)
tcp 0 85906 127.0.0.1:9080 127.0.0.1:48416
ESTABLISHED probe (1.53/0/0)
tcp 0 0 127.0.0.1:48386
127.0.0.1:9080 TIME_WAIT timewait (38.62/0/0)
mc36@stordis:~$

Archive powered by MHonArc 2.6.19.

Top of Page