Freeswitch High CPU Issue (Probably BLF related)

[ntt]

Hi,
I don't know if this is the right section, so please admin move this thread if there is a better section.
I'm using freeswitch 1.6.20, fusionpbx 4.5.12, centos 7.7 with 32Gb of ram and a dual cpu Intel(R) Xeon(R) E5649. I have only 48 extension with 50 gateway and a lot of calls (about 1.500 per day). The problem is that I see high cpu consumption by freeswitch and I do not understand why. The only thing I noticed is that the problem could be related to BLF. I see in logs "bursts" of requests like this:

cat /var/log/freeswitch/freeswitch.log | grep "192\.168\.1\.208"
2020-04-06 09:49:49.136415 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6000@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.176428 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6001@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.216429 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6002@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.256429 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6003@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.336430 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6005@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.396408 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6006@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.436429 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6007@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.476426 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6009@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.516428 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6010@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.556425 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6011@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.596426 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6012@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.716439 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6014@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.756441 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6015@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.796427 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6016@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.856429 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6018@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.916430 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6019@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.956423 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6020@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:49.996423 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6021@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.076430 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6023@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.116428 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6024@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.156428 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6025@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.196430 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6026@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.236428 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6027@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.296436 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6028@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.316423 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6029@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.436435 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6031@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.476434 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6032@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.516425 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6033@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.556430 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6034@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.596428 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6035@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.636428 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6036@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.676428 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6037@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.776407 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6039@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.816394 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6040@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.876437 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6041@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.916400 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6042@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.956428 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6043@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:50.996429 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6044@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:51.036424 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6045@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:51.116433 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6047@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:51.176422 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6048@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:51.216433 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6049@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:51.256433 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6098@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:51.296433 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6099@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:51.336403 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6100@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:49:51.396433 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [6409@xxx.yyy.mydomain.com] from ip 192.168.1.208
2020-04-06 09:55:02.996389 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [6008@xxx.yyy.mydomain.com] from ip 192.168.1.208


and this kind of message is repeated by all extension in the lan.
Please note that I have freeswitch with ip 192.168.1.5 and all extensions are in the same lan (except a couple). I'm using old linksys SPA962, Cisco Spa525g, YealinkT29 It seems that cpu consumption grows when there are these messages in log.
Please, I need some advise in order to identify and solve the issue.
Thank you,
Marco

 

[DigitalDaz]

That looks like some sort of potential hack and has nothing to do with blf.

 

[ntt]

Please, give me some advice in order to identify the problem. Actually port 5060/udp is open for all ips, but I have some doubts: requests come from phones in local lan and I'm sure that this is not an attack.
It seems to me as a blf problem because every time a call is received, all attendant console need to be updated. Anyway, the idea that cpu of freeswitch can reach 200% it's strange for me.
Thank you for you support

 

[DigitalDaz]

You need to post more logs the log you have posted indicates an extensions is calling many others. They are calls it is attempting to initiate.

 

[ntt]

Unfortunately I don't know which log should I share. I'm checking /var/log/freeswitch.log and it seems the problem is not related to a particular event (e.g.: receiving a call from a gateway). It seems some kind of "polling" made by extensions using an INVITE. Have you some idea on how I can debug this behavior? Can I use sngrep and filter only with INVITE requests? I need to understand why all extensions send INVITE to each other, or at least this seems to be the problem

 

[DigitalDaz]

You do not poll with an invite, just post a longer version of the freeswitch log rather than grepping it.

An INVITE is the initiation of a call or can be used during an ongoing call to refresh the session but it is certainly not used to poll anything.

 

[ntt]

ok. I can post a 10MB log but there are a lot of sensitive information. Is there a best practice or should I try to remove sensitive information by hand?
Thank you

 

[ntt]

DigitalDaz, I'm trying to debug in order to provide better logs. I've created a new profile named internal.lan on port 5061 and registered only one extension using this profile. Then I launched tcpdump with
tcpdump -i em1 -n port 5061

and attached log file here. Basically I see that after the "REGISTER" part, the extension (with ip 192.168.1.208) send a lot of SUBSCRIBE to freeswitch, one for each other extension. Is this a normal behavior? Furthermore I see a lot of NOTIFY from freeswitch to the extension.
As a side note, extension registers to "xxx.yyy.mydomain.com" that is the domain I created in fusionpbx, using an outbound proxy 192.168.1.5 that is the local ip of freeswitch. I did this because xxx.yyy.mydomain.com has a public ip and I'd like to use local ip address for traffic in lan. Is this correct?
Thank you

 

[pbxcom]

DigitalDaz, I'm trying to debug in order to provide better logs. I've created a new profile named internal.lan on port 5061 and registered only one extension using this profile. Then I launched tcpdump with
tcpdump -i em1 -n port 5061

and attached log file here. Basically I see that after the "REGISTER" part, the extension (with ip 192.168.1.208) send a lot of SUBSCRIBE to freeswitch, one for each other extension. Is this a normal behavior? Furthermore I see a lot of NOTIFY from freeswitch to the extension.
As a side note, extension registers to "xxx.yyy.mydomain.com" that is the domain I created in fusionpbx, using an outbound proxy 192.168.1.5 that is the local ip of freeswitch. I did this because xxx.yyy.mydomain.com has a public ip and I'd like to use local ip address for traffic in lan. Is this correct?
Thank you

Hey @ntt , I have a similar issue, did you ever get this resolved? Was it really due to BLF?