Asterisk FreePBX Network lag latency

we have FreePBX server with the last update versions
and hardware resources (CPU 8 virtual core intel xeon , RAM 12 G, and 10g dedicated Lan card )
the issue is when tow person A and B talk the call drop many time ,
and when i ping to server some time i have high latency more then 700ms and have
time out some time and i don’t now way any one have idea

Can you give us some more information about the network setup? Logs? Etc?

thank you for reply

the lan config is

vi /etc/sysconfig/network-scripts/ifcfg-eth0

FreePBX Sysadmin Generated network configuration.

This file was generated at 2019-03-01T11:37:53+00:00

DEVICE=eth0

BOOTPROTO=static
ONBOOT=‘yes’
IPADDR=10.10.20.10
NETMASK=255.255.255.0
GATEWAY=10.10.20.1
PEERDNS=no
IPV6_PEERDNS=no

about log you mean full log ?? can you send me the command line to apply to show you the log you want ,many thanks

and this DEBUG log is normal

[2019-04-27 22:23:02] [2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2019-04-27 22:23:02] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.35.223’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from ‘[email protected]:5060’ to ‘[email protected]:5060’
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.35.223:2048
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:4538 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:6595 sip_pvt_dtor: Destroying SIP dialog [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2019-04-27 22:23:02] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.35.130’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from ‘[email protected]:5060’ to ‘[email protected]:5060’
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.35.130:1024
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:4538 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:6595 sip_pvt_dtor: Destroying SIP dialog [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2019-04-27 22:23:02] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.109.186’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from ‘[email protected]:5060’ to ‘[email protected]:5060’
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.109.186:1024
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2019-04-27 22:23:02] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.35.153’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from ‘[email protected]:5060’ to ‘[email protected]:5060’
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.35.153:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:4538 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:6595 sip_pvt_dtor: Destroying SIP dialog [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:4538 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:6595 sip_pvt_dtor: Destroying SIP dialog [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2019-04-27 22:23:02] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.111.200’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from ‘[email protected]:5060’ to ‘[email protected]:5060’
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.111.200:2048
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2019-04-27 22:23:02] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.35.141’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from ‘[email protected]:5060’ to ‘[email protected]:5060’
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.35.141:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:4538 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:6595 sip_pvt_dtor: Destroying SIP dialog [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:4538 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:6595 sip_pvt_dtor: Destroying SIP dialog [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2019-04-27 22:23:02] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.35.213’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from ‘[email protected]:5060’ to ‘[email protected]:5060’
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.35.213:5060
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:4538 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2019-04-27 22:23:02] DEBUG[2562]: chan_sip.c:6595 sip_pvt_dtor: Destroying SIP dialog [email protected]:5060
[2019-04-27 22:23:03] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.110.164’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for 386d43bfc13c-1o4ex01llyld - REGISTER (No RTP)
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘SIP/2.0 401’ onto UDP socket destined for 192.168.110.164:1024
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:17000 parse_register_contact: Store REGISTER’s src-IP:port for call routing.
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:17164 build_path: build_path: do not use Path headers
[2019-04-27 22:23:03] DEBUG[2466]: threadpool.c:517 grow: Increasing threadpool stasis-core’s size by 1
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2019-04-27 22:23:03] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.110.164’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:03] DEBUG[2677]: manager.c:6017 match_filter: Examining AMI event:
Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/03
PeerStatus: Registered
Address: 192.168.110.164:1024

[2019-04-27 22:23:03] DEBUG[17075]: manager.c:6017 match_filter: Examining AMI event:
Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/03
PeerStatus: Registered
Address: 192.168.110.164:1024

[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from ‘[email protected]:5060’ to ‘[email protected]:5060’
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.110.164:1024
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 192.168.110.164:1024
[2019-04-27 22:23:03] DEBUG[2477]: chan_sip.c:30428 sip_devicestate: Checking device state for peer 03
[2019-04-27 22:23:03] DEBUG[2477]: devicestate.c:472 do_state_change: Changing state for SIP/03 - state 1 (Not in use)
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:4538 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:6595 sip_pvt_dtor: Destroying SIP dialog [email protected]:5060
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:9012 __sip_alloc: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2019-04-27 22:23:03] DEBUG[2562]: acl.c:990 ast_ouraddrfor: For destination ‘192.168.102.113’, our source address is ‘10.10.20.10’.
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 10.10.20.10:5060
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from ‘[email protected]:5060’ to ‘[email protected]:5060’
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:3754 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.102.113:2048
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:4538 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2019-04-27 22:23:03] DEBUG[2562]: chan_sip.c:6595 sip_pvt_dtor: Destroying SIP dialog [email protected]:5060
AsteriskNOW*CLI> core set debug off
Core debug was 3 and is now OFF.

[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:38] ERROR[18912][C-0000007b]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2019-04-27 22:23:42] NOTICE[2562]: chan_sip.c:24708 handle_response_peerpoke: Peer ‘653’ is now Lagged. (2040ms / 2000ms)
[2019-04-27 22:23:52] NOTICE[2562]: chan_sip.c:24708 handle_response_peerpoke: Peer ‘653’ is now Reachable. (64ms / 2000ms)

OK so ICMP (ping) is one of the least important services to a system. It will be one of the first things it stops dealing with when the system is too busy.

It would appear you are pinging one local network segment (10.10.20.10) from another (192.168.35.223) so is the PBX on some sort of private LAN connection with the provider? Why is the PBX on a different LAN segment if it’s not?

Additionally, how are these two segments connected? Are they on a managed or dumb switch? Are there VLANs involved? If this is a private LAN with the carrier for the PBX, is there latency between the PBX and the carrier side of it? Or is this latency only between these two network segments?

we have vlans for each service and network all network is internal and in same Data Center , for Voip serve the network is 10.10.10.20.10/24
for phone we have Voice Vlan and the network is 192.168.35.0/24, the issue is person A make call with person B some time have drop in the call no voice or lag in the call after investigation i notice when the ping is time out or high latency more then 300ms the voice disper for 1second or 2 second , my qution why i have this drop or lag
all switch is cisco 2960X and 3750X , the server work fine for 1 month and after that we have this issue

Well are you looking at the PBX when this happens or just pings? Don’t confuse network congestion with server load. You need to verify if the server is actually under a lot of load when this is happening or is your network in general under load?

the max number of active call in same time is 15 at the max ,the server use 15% From CPU and 1G ram and 9G free, the problem is this issue This problem occurs even no active call

Then you need to look at your network. You clearly have network congestion happening.

im not sure about that coz we have anthoer server in same Network work fine plus why this issue occurs now the server work fine for more the 1 month ,Previously we have an old freePBX server and we upgrade for last version new server new instillation everything is new , just use the same ip and we apply same policy

This is sounding like a local networking issue. You can tell us all day how other things on the network are working fine but that doesn’t rule out anything. Most other things aren’t using UDP which for SIP has a low tolerance for network issues unlike TCP which has a much higher tolerance.

30ms latency isn’t going to do much to impact your youtube video but it will impact your SIP call.

do you have a log command to apply to see what happens
:sob::sob::sob::sob::sob::sob::sob:

why you are so sure its network issue not a server issue or service , ok if its network issue why now occurred or why not happen all time this issue occurred even in the weekend we tested that in in the weekend and same issue

No, I don’t. You can run tcpdump and get a trace and look at it. But if you’re having high ping times to the server even when there are no calls and the server under 20% load I’m not sure how this is a server issue overall.

Can’t troubleshoot your network.

ok i will make a clone from my server and tested in Test zone and i will share with you the result i will make the voip server and the phone in same network 2 phone for test ,many thanks for your time

What you’re describing sounds a lot like having two machines on the same network with the same IP address. That’s what I’d be looking for. Are you sure the old machine is turned off?

Yes sure we shutdown the old server
Do you have any idea ??

You have two machines using the same IP, or, there is some other low-level network issue (faulty network cable, bad port on the switch or on the network card)

The old server we change the ip and shutdown ,

Now we move the voip machines to another server and we monitor the service