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

    NTP / Clock Unsynchronized error after KVM kernel upgrade

    Scheduled Pinned Locked Moved General pfSense Questions
    4 Posts 2 Posters 1.2k 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.
    • S
      shshs
      last edited by shshs

      Greetings,

      I'll be appreciated for your help with the following issue. We have latest pfSense VM in HA configuration works as NPT client (of public pools) and server (for LAN nodes). We use KVM CentOS to run those VMs and after the latest upgrade from kernel version 3.10.0-957.el7.x86_64 to **3.10.0-1160.11.1.**el7.x86_64 clock synchronisation on pfSense VMs stopped working.

      My ntp settings:

      [2.4.5-RELEASE][admin@]/root: cat /var/etc/ntpd.conf 
      # 
      # pfSense ntp configuration file 
      # 
      
      tinker panic 0 
      # Orphan mode stratum
      tos orphan 2
      
      
      # Upstream Servers
      pool 0.pfsense.pool.ntp.org iburst maxpoll 9 prefer
      pool 1.pfsense.pool.ntp.org iburst maxpoll 9
      pool 2.pfsense.pool.ntp.org iburst maxpoll 9
      
      
      enable stats
      statistics clockstats loopstats peerstats
      statsdir /var/log/ntp
      logconfig =syncall +clockall +peerall +sysall
      driftfile /var/db/ntpd.drift
      restrict default kod limited nomodify nopeer notrap
      restrict -6 default kod limited nomodify nopeer notrap
      restrict source kod limited nomodify notrap
      interface ignore all
      interface ignore wildcard
      interface listen vtnet1.1
      [2.4.5-RELEASE][admin@]/root: 
      

      NTP client sends/receives data from public pool:

      [2.4.5-RELEASE][admin@]/root: ntpdate -dv 0.pfsense.pool.ntp.org
       7 Jan 14:03:14 ntpdate[7583]: ntpdate 4.2.8p14@1.3728-o Thu Mar  5 17:03:56 UTC 2020 (1)
      transmit(34.194.39.113)
      receive(34.194.39.113)
      transmit(204.2.134.163)
      transmit(208.67.72.50)
      receive(208.67.72.50)
      transmit(172.104.226.77)
      receive(172.104.226.77)
      transmit(34.194.39.113)
      receive(34.194.39.113)
      transmit(204.2.134.163)
      transmit(208.67.72.50)
      receive(208.67.72.50)
      transmit(172.104.226.77)
      receive(172.104.226.77)
      transmit(34.194.39.113)
      receive(34.194.39.113)
      transmit(204.2.134.163)
      receive(204.2.134.163)
      transmit(208.67.72.50)
      receive(208.67.72.50)
      transmit(172.104.226.77)
      receive(172.104.226.77)
      transmit(34.194.39.113)
      receive(34.194.39.113)
      transmit(204.2.134.163)
      receive(204.2.134.163)
      transmit(208.67.72.50)
      receive(208.67.72.50)
      transmit(172.104.226.77)
      receive(172.104.226.77)
      204.2.134.163: Server dropped: strata too high
      
      server 34.194.39.113, port 123
      stratum 3, precision -24, leap 00, trust 000
      refid [209.51.161.238], root delay 0.068146, root dispersion 0.036453
      reference time:      e3a1d513.7527d506  Thu, Jan  7 2021 13:44:35.457
      originate timestamp: e3a1d978.b29aedfb  Thu, Jan  7 2021 14:03:20.697
      transmit timestamp:  e3a1d978.b93f4f65  Thu, Jan  7 2021 14:03:20.723
      filter delay:  0.03386    0.03378    0.03374    0.03383   
                     ----       ----       ----       ----      
      filter offset: -0.030041  -0.030121  -0.030056  -0.030072 
                     ----       ----       ----       ----      
      delay 0.03374, dispersion 0.00003, offset -0.030056
      
      server 204.2.134.163, port 123
      stratum 16, precision -23, leap 11, trust 000
      refid [STEP], root delay 0.000000, root dispersion 0.000168
      reference time:      (no time)
      originate timestamp: e3a1d978.ed08c46c  Thu, Jan  7 2021 14:03:20.925
      transmit timestamp:  e3a1d978.ec6f5c6f  Thu, Jan  7 2021 14:03:20.923
      filter delay:  0.00000    0.00000    0.09340    0.09364   
                     ----       ----       ----       ----      
      filter offset: +0.000000  +0.000000  -0.031582  -0.031698 
                     ----       ----       ----       ----      
      delay 0.09340, dispersion 24.00006, offset -0.031582
      
      server 208.67.72.50, port 123
      stratum 2, precision -24, leap 00, trust 000
      refid [128.227.205.3], root delay 0.018417, root dispersion 0.028046
      reference time:      e3a1d6ed.b837f301  Thu, Jan  7 2021 13:52:29.719
      originate timestamp: e3a1d979.1c527622  Thu, Jan  7 2021 14:03:21.110
      transmit timestamp:  e3a1d979.1fa30981  Thu, Jan  7 2021 14:03:21.123
      filter delay:  0.06474    0.06458    0.06453    0.06467   
                     ----       ----       ----       ----      
      filter offset: -0.032544  -0.032647  -0.032585  -0.032579 
                     ----       ----       ----       ----      
      delay 0.06453, dispersion 0.00003, offset -0.032585
      
      server 172.104.226.77, port 123
      stratum 2, precision -24, leap 00, trust 000
      refid [129.6.15.28], root delay 0.091034, root dispersion 0.025314
      reference time:      e3a1d938.3674b9be  Thu, Jan  7 2021 14:02:16.212
      originate timestamp: e3a1d979.5585ba71  Thu, Jan  7 2021 14:03:21.334
      transmit timestamp:  e3a1d979.52d82d82  Thu, Jan  7 2021 14:03:21.323
      filter delay:  0.10706    0.10814    0.10812    0.10759   
                     ----       ----       ----       ----      
      filter offset: -0.030471  -0.031088  -0.031042  -0.030539 
                     ----       ----       ----       ----      
      delay 0.10706, dispersion 0.00024, offset -0.030471
      
       7 Jan 14:03:21 ntpdate[7583]: adjust time server 208.67.72.50 offset -0.032585 sec
      [2.4.5-RELEASE][admin@]/root: 
      

      When I'm trying to sync from pfSense as its client:

      [jamal@jamalungma ~]$ ntpdate -dv <pfSense IP - 10.0.11.3>
       7 Jan 17:02:17 ntpdate[2192]: ntpdate 4.2.8p15@1.3728-o Tue Jun 23 00:00:00 UTC 2020 (1)
      Looking for host 10.0.11.3 and service ntp
      host found : 10.0.11.3
      transmit(10.0.11.3)
      receive(10.0.11.3)
      transmit(10.0.11.3)
      receive(10.0.11.3)
      transmit(10.0.11.3)
      receive(10.0.11.3)
      transmit(10.0.11.3)
      receive(10.0.11.3)
      10.0.11.3: Server dropped: Leap not in sync
      server 10.0.11.3, port 123
      stratum 2, precision -18, leap 11, trust 000
      refid [163.237.218.18], root delay 0.020844, root dispersion 0.017929
      reference time:      e3a1dd82.34b2cb6d  Thu, Jan  7 2021 19:20:34.205
      originate timestamp: e3a1dfea.c453e0bc  Thu, Jan  7 2021 19:30:50.766
      transmit timestamp:  e3a1dfea.6eb420bb  Thu, Jan  7 2021 19:30:50.432
      filter delay:  0.16284    0.18611    0.16600    0.16328   
                     ----       ----       ----       ----      
      filter offset: +19.497126 +19.508922 +19.497515 +19.495252
                     ----       ----       ----       ----      
      delay 0.16284, dispersion 0.00249, offset +19.497126
      
       7 Jan 17:02:23 ntpdate[2192]: no server suitable for synchronization found
      [jamal@jamalungma ~]$
      

      I searched for some errors in ntpd logs and I got this precisely after KVM kernel upgrade, a lot of these messages:

      Jan  7 12:18:08 pfSenseB ntpd[75414]: 0.0.0.0 c01d 0d kern kernel time sync disabled
      Jan  7 12:18:08 pfSenseB ntpd[45063]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
      

      One thing I also noticed that pfSense use ACPI clock source and KVM uses TSC

      [2.4.5-RELEASE][admin@]/root: sysctl kern.timecounter
      kern.timecounter.tsc_shift: 1
      kern.timecounter.smp_tsc_adjust: 0
      kern.timecounter.smp_tsc: 0
      kern.timecounter.invariant_tsc: 0
      kern.timecounter.fast_gettime: 1
      kern.timecounter.tick: 1
      kern.timecounter.choice: i8254(0) ACPI-fast(900) TSC-low(-100) dummy(-1000000)
      kern.timecounter.hardware: ACPI-fast
      kern.timecounter.alloweddeviation: 5
      kern.timecounter.timehands_count: 2
      kern.timecounter.stepwarnings: 0
      kern.timecounter.tc.i8254.quality: 0
      kern.timecounter.tc.i8254.frequency: 1193182
      kern.timecounter.tc.i8254.counter: 1077
      kern.timecounter.tc.i8254.mask: 65535
      kern.timecounter.tc.ACPI-fast.quality: 900
      kern.timecounter.tc.ACPI-fast.frequency: 3579545
      kern.timecounter.tc.ACPI-fast.counter: 4144087
      kern.timecounter.tc.ACPI-fast.mask: 16777215
      kern.timecounter.tc.TSC-low.quality: -100
      kern.timecounter.tc.TSC-low.frequency: 1149932904
      kern.timecounter.tc.TSC-low.counter: 2121589485
      kern.timecounter.tc.TSC-low.mask: 4294967295
      [2.4.5-RELEASE][admin@]/root:
      

      I changed different parameters in NTP configuration page first, restarted ntp server via gui bunch of times. A day later I reboot VM few times, changing pfSense sysctl variable kern.timecounter.hardware from ACPI-fast to TSC-low . After a few reboots of pfSense VMs NTP magically synchronised.

      After the last reboot kern.timecounter.hardware value is ACPI-fast even though I put it like:

      [2.4.5-RELEASE][admin@]/root: sysctl kern.timecounter.hardware=TSC-low
      kern.timecounter.hardware: ACPI-fast -> TSC-low
      [2.4.5-RELEASE][admin@]/root: sysctl kern.timecounter.hardware
      kern.timecounter.hardware: TSC-low
      

      but time was finally synchronised:

      [2.4.5-RELEASE][admin@]/root: ntptime 
      ntp_gettime() returns code 0 (OK)
        time e3a1de64.2b2a0664  Thu, Jan  7 2021 14:24:20.168, (.168610934),
        maximum error 591133 us, estimated error 343 us, TAI offset 0
      ntp_adjtime() returns code 0 (OK)
        modes 0x0 (),
        offset -10.219 us, frequency 0.116 ppm, interval 4 s,
        maximum error 591133 us, estimated error 343 us,
        status 0x2001 (PLL,NANO),
        time constant 7, precision 0.001 us, tolerance 496 ppm,
        pps frequency 0.000 ppm, stability 0.000 ppm, jitter 0.000 us,
        intervals 0, jitter exceeded 0, stability exceeded 0, errors 0.
      [2.4.5-RELEASE][admin@]/root: 
      

      The second pfSense VM is still not synchronised, NTP configuration files are the same on both VMs, but ntptime shows OK on first one and ERROR on the other. I don't know what is changed after manipulations with first pfSense VM, but all parameters from NTP settings to sysctl variables remains the same as they were before KVM kernel upgrade.

      Please suggest me what should be checked in addition.

      1 Reply Last reply Reply Quote 0
      • stephenw10S
        stephenw10 Netgate Administrator
        last edited by

        ntp can take quite some time before it sees the source as valid and syncs.

        In a VM the emulated hardware can appear to be far less stable as the hypervisor switches CPU time between VMs.

        Normally ACPI-Fast would be a far better timeounter to use the TSC-slow. You can see the time quality listed. Even i8254 shows as better.

        What is a the error message actually seen when trying to sync against the secondary?

        Steve

        S 1 Reply Last reply Reply Quote 0
        • S
          shshs @stephenw10
          last edited by shshs

          Hi @stephenw10, thanks for answer

          When I'm trying to sync from the second pfSense VM, here what I get from client:

          [jamal@jamalungma ~]$ ntpdate -dv 10.0.11.254
          16 Jan 13:22:08 ntpdate[2300]: ntpdate 4.2.8p15@1.3728-o Tue Jun 23 00:00:00 UTC 2020 (1)
          Looking for host 10.0.11.254 and service ntp
          host found : 10.0.11.254
          transmit(10.0.11.254)
          transmit(10.0.11.254)
          receive(10.0.11.254)
          transmit(10.0.11.254)
          receive(10.0.11.254)
          transmit(10.0.11.254)
          receive(10.0.11.254)
          10.0.11.254: Server dropped: server has gone too long without sync
          
          server 10.0.11.254, port 123
          stratum 2, precision -16, leap 00, trust 000
          refid [127.0.0.1], root delay 0.000000, root dispersion 0.000000
          reference time:      (no time)
          originate timestamp: e3ad6707.80b783ad  Sat, Jan 16 2021 13:22:15.502
          transmit timestamp:  e3ad6706.5257518f  Sat, Jan 16 2021 13:22:14.321
          filter delay:  0.00000    0.16133    0.15317    0.30644   
                         ----       ----       ----       ----      
          filter offset: +0.000000  +1.117263  +1.112640  +1.040580 
                         ----       ----       ----       ----      
          delay 0.15317, dispersion 8.02031, offset +1.112640
          
          16 Jan 13:22:14 ntpdate[2300]: no server suitable for synchronization found
          

          The state of pfSense VM:

          [2.4.5-RELEASE][admin@]/root: ntptime
          ntp_gettime() returns code 5 (ERROR)
            time e3ad673b.c86f9000  Sat, Jan 16 2021  8:23:07.782, (.453782952),
            maximum error 16540500 us, estimated error 16000000 us, TAI offset 0
          ntp_adjtime() returns code 5 (ERROR)
            modes 0x0 (),
            offset 0.000 us, frequency 0.000 ppm, interval 4 s,
            maximum error 16540500 us, estimated error 16000000 us,
            status 0x41 (PLL,UNSYNC),
            time constant 3, precision 0.000 us, tolerance 496 ppm,
            pps frequency 0.000 ppm, stability 0.000 ppm, jitter 0.000 us,
            intervals 0, jitter exceeded 0, stability exceeded 0, errors 0.
          

          /var/log/ntpd.log:

          Jan 16 08:05:06 pfSenseC ntpd[11280]: ntpd 4.2.8p14@1.3728-o Thu Mar  5 17:03:54 UTC 2020 (1): Starting
          Jan 16 08:05:06 pfSenseC ntpd[11280]: Command line: /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
          Jan 16 08:05:06 pfSenseC ntpd[11280]: ----------------------------------------------------
          Jan 16 08:05:06 pfSenseC ntpd[11280]: ntp-4 is maintained by Network Time Foundation,
          Jan 16 08:05:06 pfSenseC ntpd[11280]: Inc. (NTF), a non-profit 501(c)(3) public-benefit
          Jan 16 08:05:06 pfSenseC ntpd[11280]: corporation.  Support and training for ntp-4 are
          Jan 16 08:05:06 pfSenseC ntpd[11280]: available at https://www.nwtime.org/support
          Jan 16 08:05:06 pfSenseC ntpd[11280]: ----------------------------------------------------
          Jan 16 08:05:06 pfSenseC ntpd[11442]: proto: precision = 12.572 usec (-16)
          Jan 16 08:05:06 pfSenseC ntpd[11442]: basedate set to 2020-02-22
          Jan 16 08:05:06 pfSenseC ntpd[11442]: gps base set to 2020-02-23 (week 2094)
          Jan 16 08:05:06 pfSenseC ntpd[11442]: Listen normally on 0 lo0 [::1]:123
          Jan 16 08:05:06 pfSenseC ntpd[11442]: Listen normally on 1 lo0 127.0.0.1:123
          Jan 16 08:05:06 pfSenseC ntpd[11442]: Listen normally on 2 vtnet1.42 [fe80::5054:ff:fe64:8034%9]:123
          Jan 16 08:05:06 pfSenseC ntpd[11442]: Listen normally on 3 vtnet1.42 10.0.11.254:123
          Jan 16 08:05:06 pfSenseC ntpd[11442]: Listen normally on 4 vtnet1.42 10.0.11.3:123
          Jan 16 08:05:06 pfSenseC ntpd[11442]: Listening on routing socket on fd #25 for interface updates
          Jan 16 08:05:06 pfSenseC ntpd[11442]: 0.0.0.0 8811 81 mobilize assoc 45286
          Jan 16 08:05:06 pfSenseC ntpd[11442]: 0.0.0.0 8811 81 mobilize assoc 45287
          Jan 16 08:05:06 pfSenseC ntpd[11442]: 0.0.0.0 8811 81 mobilize assoc 45288
          Jan 16 08:05:06 pfSenseC ntpd[11442]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
          Jan 16 08:05:06 pfSenseC ntpd[11442]: 0.0.0.0 c01d 0d kern kernel time sync enabled
          Jan 16 08:05:06 pfSenseC ntpd[11442]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
          Jan 16 08:05:06 pfSenseC ntpd[11442]: 0.0.0.0 c012 02 freq_set kernel 0.000 PPM
          

          ntpq:

          [2.4.5-RELEASE][admin@]/root: ntpq -p
               remote           refid      st t when poll reach   delay   offset  jitter
          ==============================================================================
           0.pfsense.pool. .POOL.          16 p    -   64    0    0.000   +0.000   0.015
           1.pfsense.pool. .POOL.          16 p    -   64    0    0.000   +0.000   0.015
           2.pfsense.pool. .POOL.          16 p    -   64    0    0.000   +0.000   0.015
          

          Any suggestions?

          1 Reply Last reply Reply Quote 0
          • stephenw10S
            stephenw10 Netgate Administrator
            last edited by

            Hmm, well ntpd won't respond if it thinks it is not sync'd itself, which looks like the case here.

            What if you try to manually sync the Secondary from the command line? Against the Primary maybe? Or some external time source?

            Steve

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