Bug #8477
Gateway latency, units used inconsistently.
100%
Description
When a gateway alarm is triggered or cleared is is reported in the system log using milliseconds (ms) but the gateway log using microseconds (us).
System log:
Apr 22 07:32:13 rc.gateway_alarm 84386 >>> Gateway alarm: OPT4_VPNV4 (Addr:172.27.114.129 Alarm:0 RTT:120183ms RTTsd:634ms Loss:0%)
Gateway log:
Apr 22 07:32:13 dpinger OPT4_VPNV4 172.27.114.129: Clear latency 120183us stddev 634us loss 0%
That value looks to be clearly in microseconds.
Associated revisions
Change us to ms for gateway alarm.
Fixes #8477 looking to be more consitent changed to use ms for gateway alarm.
Thanks to Luke Hamburg for helping with this and the code idea.
Keeping it as 0.xxxms for under 1 millisecond responses.
Just to stay ms as much as possible.
History
#1
Updated by Anonymous over 2 years ago
- Status changed from New to Assigned
- Assignee set to Anonymous
#2
Updated by Anonymous over 2 years ago
- Status changed from Assigned to Feedback
- % Done changed from 0 to 100
Applied in changeset 040a1579e474290abfc7a4a445e310ce8e462847.
#3
Updated by → luckman212 over 2 years ago
Since I think "ms" is much more widely used and easier to comprehend, how about using
echo ">>> Gateway alarm: ${GW} (Addr:${alarm_addr} Alarm:${alarm_flag} RTT:$( expr ${alarm_rtt} / 1000 )ms RTTsd:$( expr ${alarm_rttsd} / 1000 )ms Loss:${alarm_loss}%)" | /usr/bin/logger -p daemon.info -i -t rc.gateway_alarm
instead?
#4
Updated by Steve Wheeler over 2 years ago
System log now shows:
Jul 22 19:49:56 rc.gateway_alarm 12028 >>> Gateway alarm: WAN_DHCP (Addr:172.21.16.1 Alarm:1 RTT:196us RTTsd:17us Loss:22%)
And gateway log shows:
Jul 22 19:49:56 dpinger WAN_DHCP 172.21.16.1: Alarm latency 196us stddev 17us loss 22%
So consistent there. But the initial output and config is inb milliseconds:
Jul 22 17:53:02 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 172.21.16.1 bind_addr 172.21.16.82 identifier "WAN_DHCP "
Milliseconds is the expected unit there IMO.
#5
Updated by → luckman212 over 2 years ago
Steve:
For the first case (rc.gateway_alarm), how about the change I suggested over on the github commit?
https://github.com/pfsense/pfsense/commit/040a1579e474290abfc7a4a445e310ce8e462847#commitcomment-29773284
For the other 2 (dpinger) we need to update the way dpinger.c outputs to the log, to similarly show in ms if ms > 1, otherwise show in usec
https://github.com/dennypage/dpinger/blob/master/dpinger.c#L660
https://github.com/dennypage/dpinger/blob/master/dpinger.c#L1412
It should be pretty easy to add a quick function to dpinger.c and use it when logging. I could try to make it myself, but Denny could probably do it in his sleep
#6
Updated by Steve Wheeler over 2 years ago
Personally I can live with seeing '0.196ms' there. Let's see what Stephen suggests when he gets gets the feedback.
However I can see the reasoning behind using µs everywhere.
#7
Updated by Anonymous over 2 years ago
I'll work on making it milliseconds for everything to be consistent. I added the code you suggested Luke for the gateway alarm I am however using the format 0.xxxms instead of us just to try and keep it as much ms as possible.
print_rtt() {
usec=$1
if [ "$usec" -lt "1000" ]; then
retval="0.${usec}ms"
else
retval="$( expr ${usec} / 1000 )ms"
fi
echo $retval
}
#8
Updated by Anonymous over 2 years ago
Change made here 37be6b260f8b90393d994c40e2db34925acaa451. I'll have to look into the best way to get that into dpinger as well.
#9
Updated by → luckman212 over 2 years ago
Stephen, That change looks problematic.
I made a comment on the commit but adding one here for completeness.
Example, if the rtt is 10usec, it will print as 0.10ms which actually == 100usec.
If you want everything in ms explicitly, you don't need the if anymore, just use something like
print_rtt() {
usec_to_ms="$( expr $1 / 1000 )ms"
echo $usec_to_ms
}
or maybe just
print_rtt() {
echo "$( expr $1 / 1000 )ms"
}#10
Updated by Anonymous over 2 years ago
Good catch. I'll change that. Do we care about decimal precision? anything under 1 ms will round to 0. I don't know if this matters or not. I can use bc to get some decimal precision if needs be. I haven't actually used these alarms so I don't know what is expected here.
#11
Updated by → luckman212 over 2 years ago
Good point about expr only doing integer math. For floats we could use bc
print_rtt() {
usec=$1
usec_to_ms=$( echo "scale=3; ${usec}/1000" | bc -l )
echo "${usec_to_ms}ms"
}
#12
Updated by Anonymous over 2 years ago
Awesome, Thanks for your help. I made the change you have above to the code here. 21daa13ee2642a5f4821382a46be2dfc71ba2b5a
#13
Updated by → luckman212 over 2 years ago
I made a rough PR for dpinger.c that also replicates this "usec to ms" format change. Minimal testing, but it works on my end. Submitted a PR here:
https://github.com/dennypage/dpinger/pull/32
#14
Updated by Vladimir Lind over 2 years ago
- Status changed from Feedback to Confirmed
Tested on 2.4.4-DEVELOPMENT (arm) built on Thu Aug 02 10:54:34 EDT 2018
Looks good.
GW log:
Aug 10 14:25:12 dpinger OPENVPN_SERVER_VPNV4 10.254.254.2: Alarm latency 5364us stddev 1676us loss 21%
Syslog:
Aug 10 14:25:12 rc.gateway_alarm 69623 >>> Gateway alarm: OPENVPN_SERVER_VPNV4 (Addr:10.254.254.2 Alarm:1 RTT:5.364ms RTTsd:1.676ms Loss:21%)
#15
Updated by Vladimir Lind over 2 years ago
- Status changed from Confirmed to Resolved
#16
Updated by → luckman212 over 2 years ago
Before this gets closed out, can the PR 32 for the dpinger.c update get merged as well so everything is consistent (ms)?
Changed ms to us Fixes #8477