Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    RRD Quality Delay values wrong after updating to 2.2

    Scheduled Pinned Locked Moved Problems Installing or Upgrading pfSense Software
    21 Posts 10 Posters 3.1k Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • W
      wbond
      last edited by

      FWIW I've noticed the same issue on my system.  Real RTT is about 25ms, but RTT reported is showing mid to low single digits and sometimes less than 1ms.  Yours is the first post I've noticed about it, so I'm guessing it's not a wirespread issue.  Mine was a full install to a SSD and then I restored a 2.1.5 backup.

      1 Reply Last reply Reply Quote 0
      • C
        cmb
        last edited by

        Could you enable gateway monitoring debug logging under System>Advanced, Misc, check "Enable gateway monitoring debug logging", and post your apinger logs?

        1 Reply Last reply Reply Quote 0
        • W
          wbond
          last edited by

          Sure, not sure how much data you need to see, but here's a short section of the log.  Let me know if you'd like to see more.  Right now the gateway widget is showing a RTT of 5.4ms, but it's going up and down.

          Jan 29 21:45:05 apinger: Polling, timeout: 0.953s
          Jan 29 21:45:05 apinger: (avg. loss: 0.0%)
          Jan 29 21:45:05 apinger: (avg: 6.866ms)
          Jan 29 21:45:05 apinger: #441487 from WAN_PPPOE(67.41.239.70) delay: 46.566ms/22.347ms/68.662ms received = 441484
          Jan 29 21:45:04 apinger: Polling, timeout: 0.999s
          Jan 29 21:45:04 apinger: Recently lost packets: 0
          Jan 29 21:45:04 apinger: Sending ping #441487 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:45:04 apinger: Polling, timeout: 0.977s
          Jan 29 21:45:04 apinger: (avg. loss: 0.0%)
          Jan 29 21:45:04 apinger: (avg: 4.444ms)
          Jan 29 21:45:04 apinger: #441486 from WAN_PPPOE(67.41.239.70) delay: 22.040ms/27.757ms/44.443ms received = 441483
          Jan 29 21:45:03 apinger: Polling, timeout: 0.999s
          Jan 29 21:45:03 apinger: Recently lost packets: 0
          Jan 29 21:45:03 apinger: Sending ping #441486 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:45:02 apinger: Polling, timeout: 0.975s
          Jan 29 21:45:02 apinger: (avg. loss: 0.0%)
          Jan 29 21:45:02 apinger: (avg: 5.016ms)
          Jan 29 21:45:02 apinger: #441485 from WAN_PPPOE(67.41.239.70) delay: 24.748ms/22.494ms/50.160ms received = 441482
          Jan 29 21:45:02 apinger: Polling, timeout: 0.999s
          Jan 29 21:45:02 apinger: Recently lost packets: 0
          Jan 29 21:45:02 apinger: Sending ping #441485 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:45:01 apinger: Polling, timeout: 0.977s
          Jan 29 21:45:01 apinger: (avg. loss: 0.0%)
          Jan 29 21:45:01 apinger: (avg: 4.791ms)
          Jan 29 21:45:01 apinger: #441484 from WAN_PPPOE(67.41.239.70) delay: 22.048ms/21.727ms/47.906ms received = 441481
          Jan 29 21:45:01 apinger: Polling, timeout: 0.999s
          Jan 29 21:45:01 apinger: Recently lost packets: 0
          Jan 29 21:45:01 apinger: Sending ping #441484 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:45:01 apinger: Polling, timeout: 0.375s
          Jan 29 21:45:00 apinger: Polling, timeout: 0.544s
          Jan 29 21:45:00 apinger: (avg. loss: 0.0%)
          Jan 29 21:45:00 apinger: (avg: 4.758ms)
          Jan 29 21:45:00 apinger: #441483 from WAN_PPPOE(67.41.239.70) delay: 45.166ms/21.892ms/47.585ms received = 441480
          Jan 29 21:45:00 apinger: Polling, timeout: 0.589s
          Jan 29 21:45:00 apinger: Recently lost packets: 0
          Jan 29 21:45:00 apinger: Sending ping #441483 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:59 apinger: Polling, timeout: 0.977s
          Jan 29 21:44:59 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:59 apinger: (avg: 2.431ms)
          Jan 29 21:44:59 apinger: #441482 from WAN_PPPOE(67.41.239.70) delay: 21.904ms/21.893ms/24.311ms received = 441479
          Jan 29 21:44:59 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:59 apinger: Recently lost packets: 0
          Jan 29 21:44:59 apinger: Sending ping #441482 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:58 apinger: Polling, timeout: 0.978s
          Jan 29 21:44:58 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:58 apinger: (avg: 2.430ms)
          Jan 29 21:44:58 apinger: #441481 from WAN_PPPOE(67.41.239.70) delay: 21.739ms/57.132ms/24.300ms received = 441478
          Jan 29 21:44:58 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:58 apinger: Recently lost packets: 0
          Jan 29 21:44:58 apinger: Sending ping #441481 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:57 apinger: Polling, timeout: 0.975s
          Jan 29 21:44:57 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:57 apinger: (avg: 5.969ms)
          Jan 29 21:44:57 apinger: #441480 from WAN_PPPOE(67.41.239.70) delay: 24.143ms/23.919ms/59.693ms received = 441477
          Jan 29 21:44:57 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:57 apinger: Recently lost packets: 0
          Jan 29 21:44:57 apinger: Sending ping #441480 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:56 apinger: Polling, timeout: 0.977s
          Jan 29 21:44:56 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:56 apinger: (avg: 5.947ms)
          Jan 29 21:44:56 apinger: #441479 from WAN_PPPOE(67.41.239.70) delay: 22.045ms/21.900ms/59.469ms received = 441476
          Jan 29 21:44:56 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:56 apinger: Recently lost packets: 0
          Jan 29 21:44:56 apinger: Sending ping #441479 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:56 apinger: Polling, timeout: 0.213s
          Jan 29 21:44:55 apinger: Polling, timeout: 0.706s
          Jan 29 21:44:55 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:55 apinger: (avg: 5.932ms)
          Jan 29 21:44:55 apinger: #441478 from WAN_PPPOE(67.41.239.70) delay: 34.800ms/21.587ms/59.324ms received = 441475
          Jan 29 21:44:55 apinger: Polling, timeout: 0.741s
          Jan 29 21:44:55 apinger: Recently lost packets: 0
          Jan 29 21:44:55 apinger: Sending ping #441478 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:54 apinger: Polling, timeout: 0.977s
          Jan 29 21:44:54 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:54 apinger: (avg: 4.611ms)
          Jan 29 21:44:54 apinger: #441477 from WAN_PPPOE(67.41.239.70) delay: 22.347ms/23.689ms/46.111ms received = 441474
          Jan 29 21:44:54 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:54 apinger: Recently lost packets: 0
          Jan 29 21:44:54 apinger: Sending ping #441477 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:53 apinger: Polling, timeout: 0.972s
          Jan 29 21:44:53 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:53 apinger: (avg: 4.745ms)
          Jan 29 21:44:53 apinger: #441476 from WAN_PPPOE(67.41.239.70) delay: 27.757ms/22.194ms/47.453ms received = 441473
          Jan 29 21:44:53 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:53 apinger: Recently lost packets: 0
          Jan 29 21:44:53 apinger: Sending ping #441476 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:52 apinger: Polling, timeout: 0.977s
          Jan 29 21:44:52 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:52 apinger: (avg: 4.189ms)
          Jan 29 21:44:52 apinger: #441475 from WAN_PPPOE(67.41.239.70) delay: 22.494ms/21.745ms/41.890ms received = 441472
          Jan 29 21:44:52 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:52 apinger: Recently lost packets: 0
          Jan 29 21:44:52 apinger: Sending ping #441475 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:51 apinger: Polling, timeout: 0.978s
          Jan 29 21:44:51 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:51 apinger: (avg: 4.114ms)
          Jan 29 21:44:51 apinger: #441474 from WAN_PPPOE(67.41.239.70) delay: 21.727ms/21.726ms/41.141ms received = 441471
          Jan 29 21:44:51 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:51 apinger: Recently lost packets: 0
          Jan 29 21:44:51 apinger: Sending ping #441474 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:51 apinger: Polling, timeout: 0.066s
          Jan 29 21:44:50 apinger: Polling, timeout: 0.857s
          Jan 29 21:44:50 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:50 apinger: (avg: 4.114ms)
          Jan 29 21:44:50 apinger: #441473 from WAN_PPPOE(67.41.239.70) delay: 21.892ms/22.039ms/41.140ms received = 441470
          Jan 29 21:44:50 apinger: Polling, timeout: 0.879s
          Jan 29 21:44:50 apinger: Recently lost packets: 0
          Jan 29 21:44:50 apinger: Sending ping #441473 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:49 apinger: Polling, timeout: 0.977s
          Jan 29 21:44:49 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:49 apinger: (avg: 4.129ms)
          Jan 29 21:44:49 apinger: #441472 from WAN_PPPOE(67.41.239.70) delay: 21.893ms/22.098ms/41.287ms received = 441469
          Jan 29 21:44:49 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:49 apinger: Recently lost packets: 0
          Jan 29 21:44:49 apinger: Sending ping #441472 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:48 apinger: Polling, timeout: 0.942s
          Jan 29 21:44:48 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:48 apinger: (avg: 4.149ms)
          Jan 29 21:44:48 apinger: #441471 from WAN_PPPOE(67.41.239.70) delay: 57.132ms/21.738ms/41.492ms received = 441468
          Jan 29 21:44:48 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:48 apinger: Recently lost packets: 0
          Jan 29 21:44:48 apinger: Sending ping #441471 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:47 apinger: Polling, timeout: 0.975s
          Jan 29 21:44:47 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:47 apinger: (avg: 0.610ms)
          Jan 29 21:44:47 apinger: #441470 from WAN_PPPOE(67.41.239.70) delay: 23.919ms/27.593ms/6.098ms received = 441467
          Jan 29 21:44:47 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:47 apinger: Recently lost packets: 0
          Jan 29 21:44:47 apinger: Sending ping #441470 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:46 apinger: Polling, timeout: 0.977s
          Jan 29 21:44:46 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:46 apinger: (avg: 0.977ms)
          Jan 29 21:44:46 apinger: #441469 from WAN_PPPOE(67.41.239.70) delay: 21.900ms/46.395ms/9.772ms received = 441466
          Jan 29 21:44:46 apinger: Polling, timeout: 0.999s
          Jan 29 21:44:46 apinger: Recently lost packets: 0
          Jan 29 21:44:46 apinger: Sending ping #441469 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:45 apinger: Polling, timeout: 0.973s
          Jan 29 21:44:45 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:45 apinger: (avg: 3.427ms)
          Jan 29 21:44:45 apinger: #441468 from WAN_PPPOE(67.41.239.70) delay: 21.587ms/27.604ms/34.267ms received = 441465
          Jan 29 21:44:45 apinger: Polling, timeout: 0.995s
          Jan 29 21:44:45 apinger: Recently lost packets: 0
          Jan 29 21:44:45 apinger: Sending ping #441468 to WAN_PPPOE (67.41.239.70)
          Jan 29 21:44:44 apinger: Polling, timeout: 0.976s
          Jan 29 21:44:44 apinger: (avg. loss: 0.0%)
          Jan 29 21:44:44 apinger: (avg: 4.028ms)
          Jan 29 21:44:44 apinger: #441467 from WAN_PPPOE(67.41.239.70) delay: 23.689ms/22.175ms/40.284ms received = 441464

          1 Reply Last reply Reply Quote 0
          • W
            wbond
            last edited by

            In case it helps I'll attach a copy of the quality graph for the last week.  You can see where I installed 2.2 on Saturday.

            To be clear, I'm quite happy with 2.2, this is really a minor issue for me.

            untitled.png
            untitled.png_thumb

            1 Reply Last reply Reply Quote 0
            • K
              kejianshi
              last edited by

              5ms seems good.  See that on comcast and TWC all the time.  For years.

              You sure its not just working correctly now where it wasn't before?

              1 Reply Last reply Reply Quote 0
              • N
                neik
                last edited by

                My problem went the other way: from around 5ms to 35ms. Capturing the pings shows that there is not actually anything wrong:

                08:36:46.496455 ICMP echo request, id 3767, seq 53505, length 44
                08:36:46.500664 ICMP echo reply, id 3767, seq 53505, length 44
                08:36:47.496452 ICMP echo request, id 3767, seq 53761, length 44
                08:36:47.501089 ICMP echo reply, id 3767, seq 53761, length 44
                08:36:48.497399 ICMP echo request, id 3767, seq 54017, length 44
                08:36:48.501712 ICMP echo reply, id 3767, seq 54017, length 44
                08:36:49.498143 ICMP echo request, id 3767, seq 54273, length 44
                08:36:49.502348 ICMP echo reply, id 3767, seq 54273, length 44
                08:36:50.498388 ICMP echo request, id 3767, seq 54529, length 44
                08:36:50.502767 ICMP echo reply, id 3767, seq 54529, length 44
                08:36:51.499141 ICMP echo request, id 3767, seq 54785, length 44
                08:36:51.503391 ICMP echo reply, id 3767, seq 54785, length 44
                08:36:52.499137 ICMP echo request, id 3767, seq 55041, length 44
                08:36:52.503104 ICMP echo reply, id 3767, seq 55041, length 44

                Here is the apinger log. I guess the 60ms value is raising the average?

                Jan 30 08:46:36 apinger: Polling, timeout: 0.692s
                Jan 30 08:46:36 apinger: (avg. loss: 0.0%)
                Jan 30 08:46:36 apinger: (avg: 5.866ms)
                Jan 30 08:46:36 apinger: #1055 from WAN_PPPOE(62.3.84.23) delay: 4.280ms/6.347ms/58.662ms received = 1054
                Jan 30 08:46:36 apinger: Polling, timeout: 0.697s
                Jan 30 08:46:36 apinger: Recently lost packets: 0
                Jan 30 08:46:36 apinger: Sending ping #1055 to WAN_PPPOE (62.3.84.23)
                Jan 30 08:46:35 apinger: Polling, timeout: 0.993s
                Jan 30 08:46:35 apinger: (avg. loss: 0.0%)
                Jan 30 08:46:35 apinger: (avg: 6.073ms)
                Jan 30 08:46:35 apinger: #1054 from WAN_PPPOE(62.3.84.23) delay: 4.648ms/4.398ms/60.729ms received = 1053
                Jan 30 08:46:35 apinger: Polling, timeout: 0.998s
                Jan 30 08:46:35 apinger: Recently lost packets: 0
                Jan 30 08:46:35 apinger: Sending ping #1054 to WAN_PPPOE (62.3.84.23)

                ![zen latency increase.png](/public/imported_attachments/1/zen latency increase.png)
                ![zen latency increase.png_thumb](/public/imported_attachments/1/zen latency increase.png_thumb)

                1 Reply Last reply Reply Quote 0
                • W
                  wbond
                  last edited by

                  In my case the ping command shows around 22ms, whereas the RTT in the gateway widget at the same time is showing 0.7ms.  I think it was correctly displayed in 2.1.5 but 2.2 is too low.

                  1 Reply Last reply Reply Quote 0
                  • K
                    kejianshi
                    last edited by

                    Sorry man - That graph looks like 4 or 5 ms to me, which seems good but not too good to be true.

                    (I am sipping wine as I critique the post though - It's a good strong Cabernet, so itt may be influencing my judgement)

                    1 Reply Last reply Reply Quote 0
                    • W
                      wbond
                      last edited by

                      I've never logged the apinger data before, but it looks like lines that list the "delay:" is showing the average/min/max and this looks correct.  I'm guessing that the RTT showing in the gateway widget is showing the data from the "avg:" lines which doesn't seem to correlate.  This is a home connection via dsl 20down/0.8up.  For some reason I think that dsl tends to have higher latencies than cable.

                      1 Reply Last reply Reply Quote 0
                      • W
                        wbond
                        last edited by

                        I just noticed this post.

                        https://forum.pfsense.org/index.php?topic=87835.0

                        Restarting the apinger service seems to have fixed this issue on my system.

                        1 Reply Last reply Reply Quote 0
                        • D
                          deltix
                          last edited by

                          I'm seeing the same thing. Fresh installation, ping is 5-6ms, apinger is showing 0.5ms. After restarting apinger it looks fine.

                          1 Reply Last reply Reply Quote 0
                          • C
                            Chucko
                            last edited by

                            Thanks to wbond for letting me know about this thread. I've noticed the same thing; apinger delays are much less than a manual ping or traceroute will show; and restarting apinger corrects the problem.

                            1 Reply Last reply Reply Quote 0
                            • W
                              wbond
                              last edited by

                              It looks like in my case restarting apinger only worked for couple of hours, and now it's back to underreporting the RTT.

                              untitled.png
                              untitled.png_thumb

                              1 Reply Last reply Reply Quote 0
                              • H
                                Harvy66
                                last edited by

                                wbond, RRD is showing about 5ms, it's supposed to be about 25ms? Are you sure you're pinging the same IP address?

                                1 Reply Last reply Reply Quote 0
                                • W
                                  wbond
                                  last edited by

                                  Harvy66, yes, same ip address and it usually measures in the mid 20's using ping and was consistently in that range in 2.1.5

                                  I just pinged from pfsense and results were:

                                  PING 67.41.239.70 (67.41.239.70): 56 data bytes
                                  64 bytes from 67.41.239.70: icmp_seq=0 ttl=64 time=22.187 ms
                                  64 bytes from 67.41.239.70: icmp_seq=1 ttl=64 time=22.040 ms
                                  64 bytes from 67.41.239.70: icmp_seq=2 ttl=64 time=23.700 ms
                                  64 bytes from 67.41.239.70: icmp_seq=3 ttl=64 time=21.708 ms
                                  64 bytes from 67.41.239.70: icmp_seq=4 ttl=64 time=25.904 ms
                                  64 bytes from 67.41.239.70: icmp_seq=5 ttl=64 time=39.864 ms
                                  64 bytes from 67.41.239.70: icmp_seq=6 ttl=64 time=46.233 ms
                                  64 bytes from 67.41.239.70: icmp_seq=7 ttl=64 time=22.777 ms
                                  64 bytes from 67.41.239.70: icmp_seq=8 ttl=64 time=21.835 ms
                                  64 bytes from 67.41.239.70: icmp_seq=9 ttl=64 time=21.580 ms

                                  –- 67.41.239.70 ping statistics ---
                                  10 packets transmitted, 10 packets received, 0.0% packet loss
                                  round-trip min/avg/max/stddev = 21.580/26.783/46.233/8.347 ms

                                  The dashboard is show 2.6ms at the same time.

                                  1 Reply Last reply Reply Quote 0
                                  • K
                                    keylevel
                                    last edited by

                                    Sorry - didn't get any notifications that anyone had replied to this.

                                    Anyway - restarting apinger has put the stats back to normal. I'll keep an eye on it and see how long it looks sensible ;-)

                                    Chris

                                    1 Reply Last reply Reply Quote 0
                                    • W
                                      wbond
                                      last edited by

                                      Restarting apinger only seemed to fix it for a couple of hours for me.  I ended up changing the probe interval on the gateway to 2 seconds and changed the Down value to 20 and the RTT has been running at normal levels for 2 days now.  No idea why this would make any difference, but it seems to.

                                      1 Reply Last reply Reply Quote 0
                                      • J
                                        justincase
                                        last edited by

                                        Just to let you I tried a workaround to restart apinger when monitoring alarm goes off and it seems to do the trick for 2 days now:
                                        https://forum.pfsense.org/index.php?topic=87835.msg487013#msg487013

                                        1 Reply Last reply Reply Quote 0
                                        • K
                                          keylevel
                                          last edited by

                                          @cmb:

                                          Could you enable gateway monitoring debug logging under System>Advanced, Misc, check "Enable gateway monitoring debug logging", and post your apinger logs?

                                          I think I may have a clue here…

                                          I restarted apinger and cleared the logs.The RRD RTT values where then ok for some time, but the reported values "went silly" when the log showed:

                                          Feb 15 22:01:35 apinger: alarm canceled: GW_WAN(###) *** delay ***
                                          Feb 15 22:01:22 apinger: ALARM: GW_WAN(###) *** delay ***
                                          Feb 15 19:27:16 apinger: alarm canceled: GW_WAN(###) *** delay ***

                                          The graphs changed at the same time as the first "alarm canceled" event, so it looks like its related to the alarm clearing rather than triggering.

                                          Chris

                                          1 Reply Last reply Reply Quote 0
                                          • E
                                            epimeteo
                                            last edited by

                                            I have the same problem, a VSAT wan (supposed to be always more than 500ms) and a WIMAX (supposed to be always more than 120ms), after 2.2 upgrade (well, fresh installation) are 20/10/0ms

                                            PfSense 2.2 64bit - AtomD2550 4GB w/ 4 NIC IntelPRO1000

                                            1 Reply Last reply Reply Quote 0
                                            • First post
                                              Last post
                                            Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.