Increased RTT times
-
Hi all,
pfSense 2.4.2 with OpenVPN Client.
I have recently noticed my VPN gateway RTT times have increased from 3-4ms to between 16-20ms and I'm wondering why and if it's a problem.
I have also noticed the following in the Gateway System Logs. Related??
Jan 7 11:07:09 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 11:07:09 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 11:06:16 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 11:06:16 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 8.8.8.8 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 11:05:36 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 11:05:36 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 10:47:00 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 10:47:00 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 10:46:49 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 10:46:49 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 04:52:02 dpinger vpn_gw 10.10.100.1: Clear latency 498889us stddev 1506053us loss 0% Jan 7 04:51:38 dpinger vpn_gw 10.10.100.1: Alarm latency 502668us stddev 1511804us loss 0% Jan 6 16:35:54 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 6 16:35:54 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 6 16:35:01 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 6 16:35:01 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.58 identifier "vpn_gw " Jan 6 16:34:14 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 6 16:34:14 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.34 identifier "vpn_gw " Jan 6 12:14:24 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 6 12:14:24 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.46 identifier "vpn_gw " Jan 6 11:04:19 dpinger vpn_gw 10.10.100.1: Alarm latency 4657us stddev 331us loss 22% -
Jan 7 11:07:09 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 11:07:09 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 11:06:16 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 11:06:16 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 8.8.8.8 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 11:05:36 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 11:05:36 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 10:47:00 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 10:47:00 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 10:46:49 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 7 10:46:49 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 7 04:52:02 dpinger vpn_gw 10.10.100.1: Clear latency 498889us stddev 1506053us loss 0% Jan 7 04:51:38 dpinger vpn_gw 10.10.100.1: Alarm latency 502668us stddev 1511804us loss 0% Jan 6 16:35:54 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 6 16:35:54 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.62 identifier "vpn_gw " Jan 6 16:35:01 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 6 16:35:01 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.58 identifier "vpn_gw " Jan 6 16:34:14 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 6 16:34:14 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.34 identifier "vpn_gw " Jan 6 12:14:24 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 103.193.167.136 bind_addr 103.93.68.221 identifier "WAN_PPPOE " Jan 6 12:14:24 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.10.100.1 bind_addr 10.10.127.46 identifier "vpn_gw " Jan 6 11:04:19 dpinger vpn_gw 10.10.100.1: Alarm latency 4657us stddev 331us loss 22%The ones that say "Alarm" indicate a problem with vpn_gw. The first one indicates that you were experiencing 22% packet loss at the time. The second one indicates that your average latency was over half a second, with standard deviation of over one and a half seconds which means that you have some very high spikes in there.
It also appears that dpinger is being restarted frequently which may indicate that your WAN link is unstable. You may want to have a look at the quality graph for the WAN to see what things are like over time. (Status / Monitoring)
-
Thanks for the reply.
Here is the quality graph. Seems not too bad, yes/no?
-
The amount of packet loss seems high to me.
-
To give an idea of what your quality graph should probably look like, I included a wide range of screenshots I've done over the years. The more recent 12ms pings is because I switched to using the external target of 4.2.2.2 instead of my ISPs speedtest server. This way I could monitor my internet connection instead of just my link.
I'm assuming your PPPOE is probing an ISP target.
Two things could be at play and could be a mix-
Your link has issues
-
Your target has issues
-
-
Harvy has a particularly nice WAN link. Here is a 2 day graph from my more pedestrian link.
-
As my main concern was the increased VPN (vpn_gw) RTT times I did the graph below. Keep in mind my target is not external but 10.10.100.1.
If I graph my WAN (WAN_PPPOE) where the monitoring IP is blank in System | Routing | Gateways for the same time period I get this:
Thanks again for your help.
Greg
-
Low levels of packet loss on the WAN link will result in increased latency on the VPN link. Higher levels of packet loss on the WAN link will result in both the WAN and VPN connections resetting. This is likely why you are seeing frequent restarts of dpinger.
-
This shows the RTT for the VPN (vpn_gw) suddenly increased on Jan 6 while the packet loss does not change on either the WAN or the VPN.
-
So did you edit your vpn monitor ip? Normally out of the box setting up a vpn client connection in pfsense it will point to its own interface as the gateway - ie the vpn connection. So the RTT should be like almost nothing..
Is pfsense pointing to the far end of the vpn connection, or its own IP as the monitor?
-
So did you edit your vpn monitor ip? Normally out of the box setting up a vpn client connection in pfsense it will point to its own interface as the gateway - ie the vpn connection. So the RTT should be like almost nothing..
Is pfsense pointing to the far end of the vpn connection, or its own IP as the monitor?
As per these instructions https://vpn.ac/knowledgebase/63/OpenVPN-on-pfSense.html from my VPN Provider the VPN Monitor IP is 10.10.100.1. Do not know why that was chosen.
-
Well that is clearly some IP in their network.. If your normal wan monitoring RTT has not increased you will have to get with them on any slowdowns your seeing in their network.
-
Well that is clearly some IP in their network.. If your normal wan monitoring RTT has not increased you will have to get with them on any slowdowns your seeing in their network.
OK, Thanks for your time.
Greg
