Bug 242137 - [NTP] "Unexpected origin timestamp 0xe180e455.d15bf3fb does not match aorg 0000000000.00000000 from server" (kernel reports TIME_ERROR: 0x41: Clock Unsynchronized)
Summary: [NTP] "Unexpected origin timestamp 0xe180e455.d15bf3fb does not match aorg 00...
Status: New
Alias: None
Product: Base System
Classification: Unclassified
Component: bin (show other bugs)
Version: 12.0-STABLE
Hardware: amd64 Any
: --- Affects Some People
Assignee: Cy Schubert
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-11-21 11:54 UTC by Vinícius Zavam
Modified: 2019-12-10 12:54 UTC (History)
2 users (show)

See Also:


Attachments
13-0-amd64-r354935_dmesg.txt (92.12 KB, text/plain)
2019-11-25 09:32 UTC, Vinícius Zavam
no flags Details
13-0-amd64-r354935_pciconf.txt (25.78 KB, text/plain)
2019-11-25 09:32 UTC, Vinícius Zavam
no flags Details
STABLE_12_r354893_ntpd.log (5.43 KB, text/plain)
2019-11-26 11:58 UTC, Vinícius Zavam
no flags Details
STABLE_12_r354367_dmesg.boot.txt (58.24 KB, text/plain)
2019-12-04 10:38 UTC, Vinícius Zavam
no flags Details
STABLE_12_r354367_ntpq_rootdisp.png (72.16 KB, image/png)
2019-12-04 13:29 UTC, Vinícius Zavam
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Vinícius Zavam freebsd_committer 2019-11-21 11:54:46 UTC
*** this issue was first noticed on FreeBSD stable/12@r354367; amd64. after updating the machine to stable/12@r354893 it still persists. bare metal, no VM. OSVERSION and KERNVERSION are both 1201502.

*** it was tested in 2 different machines (same hardware with same BIOS version, drivers and so on; all up to date. dell poweredge r440).

% grep -i ntp /etc/rc.conf
ntpdate_enable="YES"
ntpd_enable="YES"
ntpd_flags="${ntpd_flags} -4 --logfile=/var/log/ntpd.log --statsdir=/etc/ntp/stats -g -g -g -G"

% grep -v ^# /etc/ntp.conf 
restrict default limited kod nomodify notrap noquery nopeer
restrict 127.0.0.1 mask 255.255.255.255
restrict 10.64.35.0 mask 255.255.255.248 nomodify notrap
server ntp1 iburst prefer
server ntp2 iburst prefer
server ntp3 iburst
server ntp4 iburst
tos orphan 3
statistics clockstats cryptostats loopstats peerstats rawstats sysstats

% uptime
12:39PM  up 19:28, 4 users, load averages: 0.33, 0.26, 0.21

% date ; ntpq -4 -n -c peers localhost
Thu Nov 21 12:39:57 CET 2019
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 10.0.5.3        134.130.4.17     2 u   14   64    1    0.172  1295.19 145.506
 10.0.5.4        192.87.106.2     2 u   12   64    1    0.199  1151.60 163.782
 10.0.32.248     134.130.4.17     2 u   15   64    1    1.039  1093.62 252.553
 10.0.32.249     192.87.106.2     2 u   14   64    1    1.064  1084.35 263.641

% tail -n5 /var/log/ntpd.log
21 Nov 11:54:19 ntpd[62796]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
21 Nov 11:54:19 ntpd[62796]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
21 Nov 11:54:27 ntpd[62796]: Doing intital time step
21 Nov 12:07:40 ntpd[62796]: receive: Unexpected origin timestamp 0xe180ee7b.1b07155c does not match aorg 0000000000.00000000 from server@10.0.32.249 xmt 0xe180ee7c.0e6de70f
21 Nov 12:12:48 ntpd[62796]: receive: Unexpected origin timestamp 0xe180efb0.0f7b03f3 does not match aorg 0000000000.00000000 from server@10.0.32.249 xmt 0xe180efb0.c5f625d7

*** the server reported above by ntpd.log is NOT always the same; also used servers from the public pool offered by ntp.org, and others.

*** stratum 1 and 2 were used to try synchonizing the clock. the machine ran with a slightly nodified 'ntp.conf' with +4 servers for a couple minutes. same behavior.

*** a reboot was conducted just in case. 

# tail /etc/ntp/stats/*.20191121
==> /etc/ntp/stats/loopstats.20191121 <==
58808 39269.319 0.000000000 41.447 0.000000238 0.000000 6
58808 39276.266 0.016292991 41.447 0.005760442 0.000000 6
58808 39280.272 0.024378028 41.447 0.006099659 0.000000 6
58808 39283.292 0.028349141 41.447 0.005875910 0.000000 6
58808 39284.325 0.031962872 41.447 0.005642953 0.000000 6
58808 39648.103 0.000000000 41.447 0.000000238 0.000000 6
58808 40060.057 0.000000000 41.447 0.000000238 0.000000 6
58808 40368.773 0.000000000 41.447 0.000000238 0.000003 6
58808 41071.263 0.000000000 41.447 0.000000238 0.000003 6
58808 41831.078 0.000000000 41.447 0.000000238 0.000003 6

==> /etc/ntp/stats/peerstats.20191121 <==
58808 41832.116 10.0.5.4 9014 1.084662017 0.000208704 7.937500151 0.000000238
58808 41832.116 10.0.5.3 9014 1.084808389 0.000198845 7.937500151 0.000000238
58808 41832.117 10.0.32.249 9074 1.084358544 0.001063677 7.937500157 0.000000238
58808 41836.090 10.0.32.248 9064 1.093624959 0.001039041 7.937500157 0.000000238
58808 41861.061 10.0.5.4 9014 1.151605000 0.000199260 3.937608976 0.066942983
58808 41921.087 10.0.5.3 9014 1.290578800 0.000184648 3.937833976 0.205770411
58808 41923.097 10.0.5.3 9014 1.295191429 0.000171885 1.937678388 0.148799025
58808 42044.123 10.0.32.248 9064 1.574754317 0.000975819 0.438625303 0.321708459
58808 42045.071 10.0.5.3 961a 1.577294399 0.000142329 0.438419041 0.325921391
58808 42107.065 10.0.32.249 9374 1.720286304 0.000934281 0.188952496 0.417919861

==> /etc/ntp/stats/rawstats.20191121 <==
58808 42045.071 10.0.5.3 10.0.5.7 3783325245.070321137 3783325246.647686701 3783325246.647714587 3783325245.070491352 0 4 4 2 6 -24 0.002029 0.038559 134.130.4.17
58808 42045.071 10.0.32.249 10.0.248.26 3783325245.070242874 3783325246.647650840 3783325246.647691908 3783325245.071362245 0 4 4 2 6 -24 0.006226 0.043961 192.87.106.2
58808 42047.107 10.0.5.7 10.0.5.4 49709281.717738837 32932065.437737468 1073119457.879780001 0.000000000 3 4 3 3 6 -22 2382364672.000000 1449198080.000000 10.0.5.3
58808 42047.107 10.0.5.4 10.0.5.7 3783325247.106494539 3783325248.688494213 3783325248.688520585 3783325247.106853646 0 4 4 2 6 -24 0.005630 0.042023 192.87.106.2
58808 42106.109 10.0.248.26 10.0.32.248 1039565025.590554219 1022787809.035393484 2062975201.462277836 0.000000000 3 4 3 3 6 -22 2382364672.000000 2422276608.000000 10.0.5.3
58808 42106.110 10.0.32.248 10.0.248.26 3783325306.108754603 3783325307.827359874 3783325307.827429942 3783325306.109918638 0 4 4 2 6 -24 0.002396 0.036011 134.130.4.17
58808 42107.064 10.0.248.26 10.0.32.249 1056342241.047421434 1039565025.799976591 2079752417.367572907 0.000000000 3 4 3 3 6 -22 2382364672.000000 2439053824.000000 10.0.5.3
58808 42107.064 10.0.5.7 10.0.5.3 1056342241.541501084 1039565025.647339527 2079752417.948276881 0.000000000 3 4 3 3 6 -22 2382364672.000000 2439053824.000000 10.0.5.3
58808 42107.064 10.0.5.3 10.0.5.7 3783325307.063579735 3783325308.784316616 3783325308.784336750 3783325307.063787127 0 4 4 2 6 -24 0.002029 0.039490 134.130.4.17
58808 42107.065 10.0.32.249 10.0.248.26 3783325307.063508592 3783325308.784262036 3783325308.784329157 3783325307.064509994 0 4 4 2 6 -24 0.006226 0.044891 192.87.106.2

==> /etc/ntp/stats/sysstats.20191121 <==
58808 1051.535 3600 288 236 288 0 0 0 0 0 0 0
58808 4660.020 3600 287 231 287 0 0 0 0 0 0 0
58808 8266.163 3600 281 227 281 0 0 0 0 0 0 0
58808 11875.331 3600 284 231 284 0 0 0 0 0 0 0
58808 15484.618 3600 288 235 288 0 0 0 0 0 0 0
58808 19091.952 3600 284 227 284 0 0 0 0 0 0 0
58808 22701.535 3600 284 238 284 0 0 0 0 0 0 0
58808 26308.724 3600 282 228 282 0 0 0 0 0 0 0
58808 29917.975 3600 286 233 286 0 0 0 0 0 0 0
58808 33526.016 3600 272 227 272 0 0 0 0 0 0 0

% date ; ntpq -4 -n -c peers localhost
Thu Nov 21 12:53:22 CET 2019
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
*10.0.5.3        134.130.4.17     2 u   11   64    1    0.168  973.772 232.305
+10.0.5.4        192.87.106.2     2 u    9   64    1    0.195  978.173 278.795
+10.0.32.248     134.130.4.17     2 u   12   64    1    1.071  684.348 162.969
+10.0.32.249     192.87.106.2     2 u   11   64    1    1.061  624.044 207.852

*** other machines running either older revisions of stable/12 or releng/12.0 and releng/12.1 are not affected.
Comment 1 Vinícius Zavam freebsd_committer 2019-11-21 11:57:28 UTC
% ntpq -4 -n -c peers ntp1
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
-81.173.193.222  130.149.17.21    2 u  560 1024  377    1.318    1.931   0.427
-81.173.193.223  193.67.79.202    2 u  501 1024  377    1.325    1.580   0.148
*134.130.4.17    .GPS.            1 u  349 1024  377    2.087   -0.340   0.078
+134.130.5.17    .GPS.            1 u  679 1024  377    2.122   -0.343   0.090
+129.143.2.23    .GPS.            1 u  930 1024  377    7.557   -0.407   0.119
-129.143.2.33    .PZF.            1 u  446 1024  377    7.556   -0.612   0.055
-194.109.6.2     193.67.79.202    2 u  544 1024  377    5.820   -0.565   0.369
-213.136.0.252   .PPS.            1 u  659 1024  377    6.473   -0.132   0.958
-192.53.103.103  .PTB.            1 u  383 1024  377   13.873    1.432   1.090
-10.0.5.4        192.87.106.2     2 s  764 1024  376    0.218   -0.158   0.105

% ntpq -4 -n -c peers ntp2
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
-81.173.193.222  130.149.17.21    2 u  752 1024  377    1.197    2.366   0.228
-81.173.193.223  193.67.79.202    2 u  802 1024  377    1.457    1.595   0.211
+134.130.4.17    .GPS.            1 u  605 1024  377    2.156   -0.173   0.048
+134.130.5.17    .GPS.            1 u  966 1024  377    2.186   -0.194   0.032
+129.143.2.23    .GPS.            1 u  118 1024  377    7.666   -0.239   0.080
-129.143.2.33    .PZF.            1 u  503 1024  377    7.487   -0.448   0.056
-194.109.6.2     193.67.79.202    2 u  393 1024  377    5.515   -0.296   0.063
*192.87.106.2    .GPS.            1 u  601 1024  377    5.719   -0.084   0.091
+192.87.36.4     .MRS.            1 u  128 1024  377    8.280    0.013   0.084
-10.0.5.3        134.130.4.17     2 s  245 1024  377    0.202    0.150   0.092
Comment 2 Vinícius Zavam freebsd_committer 2019-11-21 14:16:23 UTC
*** same hardware running releng/12.1 works fine as well
Comment 3 Vinícius Zavam freebsd_committer 2019-11-21 16:34:40 UTC
% ntpd --version
ntpd 4.2.8p12-a (1)
Comment 4 Vinícius Zavam freebsd_committer 2019-11-22 09:57:00 UTC
*** 12.1-STABLE amd64 r354893 1201502
Comment 5 Vinícius Zavam freebsd_committer 2019-11-22 10:38:48 UTC
% uptime
11:38AM  up 1 day, 18:23, 5 users, load averages: 0.53, 0.34, 0.27

% cat /var/db/ntp/ntpd.drift
48.229
Comment 6 Vinícius Zavam freebsd_committer 2019-11-22 11:32:51 UTC
recently booted the machine using 'FreeBSD-13.0-CURRENT-amd64-20191121-r354935-memstick.img' and it behaves the same as stable/12@r354893.

https://svnweb.freebsd.org/base/head/contrib/ntp/ntpd/?view=log suggests that 'ntpd' should be version 4.2.8p13, it's still 4.2.8p12 (1). just like under stable/12 (12.1-STABLE).

how to reproduce?
  1. boot usb stick with FreeBSD-13.0-CURRENT-amd64-20191121-r354935;
  2. enter shell mode;
  3. get your network settings done;
  4. run `service ntpd onestart` and wait.
Comment 7 Vinícius Zavam freebsd_committer 2019-11-22 11:33:37 UTC
FreeBSD freebsd-HEAD-13-0 13.0-CURRENT FreeBSD 13.0-CURRENT #0 r354935: Thu Nov 21 08:28:22 UTC 2019     root@releng1.nyi.freebsd.org:/usr/obj/usr/src/amd64.amd64/sys/GENERIC  amd64

11:33AM  up 1 hr, 2 users, load averages: 0.14, 0.17, 0.21

ntpq> lpeers
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 0.freebsd.pool. .POOL.          16 p    -   64    0    0.000    0.000   0.000
+193.1.12.167    230.0.204.150    2 u   59   64    1   26.073  492.557 266.495
+82-64-45-50.sub .GPS.            1 u   58   64    1   32.215  493.964 265.248
+216.6.2.70 (up2 195.219.14.21    2 u   56   64    1   91.754  490.716 265.393
+server.samoylyk 161.143.24.141   2 u   52   64    1   24.803  500.755 299.806
+v35005.php-frie 131.188.3.223    2 u   40   64    1    4.615  528.354 314.264
+stratum2-3.NTP. 129.70.130.70    2 u   20   64    7   11.671  566.456 419.030
+time02.fal.code 192.53.103.108   2 u   18   64    7    9.590  570.200 421.709
+162.159.200.123 10.48.8.4        3 u   16   64    7    1.900  573.828 420.288
+213.251.53.187  195.66.241.10    2 u   16   64    7    5.425  573.531 422.477
+ntp1.rrze.uni-e .DCFp.           1 u   16   64    7    7.907  572.864 426.169
+x8d1ee404.agdsn 85.220.190.246   3 u   16   64    7   19.868  571.959 421.706
*ntp2.rrze.uni-e .MBGh.           1 u   19   64   37    7.964  567.335 384.663

ntpq> sysinfo
associd=0 status=0613 leap_none, sync_ntp, 1 event, spike_detect,
system peer:        ntp2.rrze.uni-erlangen.de:123
system peer mode:   client
leap indicator:     00
stratum:            2
log2 precision:     -23
root delay:         7.964
root dispersion:    617.125
reference ID:       131.188.3.222
reference time:     e18245a6.3f00f24a  Fri, Nov 22 2019 11:31:50.246
system jitter:      42.259079
clock jitter:       33.033
clock wander:       0.000
broadcast delay:    -50.000
symm. auth. delay:  0.000

ntpq> version
ntpq 4.2.8p12-a (1)
Comment 8 Vinícius Zavam freebsd_committer 2019-11-22 16:58:32 UTC
that's odd: running the same 13.0-CURRENT r354935 live stick in another machine (regular PC, with an Intel Core i3-3110M@2.4Ghz) it works! the CPU on the server is an Intel Xeon Bronze 3204@1.9Ghz

current status: till 12.1-RELEASE the box with the Xeon works fine, running stable/12 (r354367 and r354893) or HEAD (r354935) NTP does not work.
Comment 9 Vinícius Zavam freebsd_committer 2019-11-25 09:32:12 UTC
Created attachment 209404 [details]
13-0-amd64-r354935_dmesg.txt

13-0-amd64-r354935_dmesg.txt
Comment 10 Vinícius Zavam freebsd_committer 2019-11-25 09:32:29 UTC
Created attachment 209405 [details]
13-0-amd64-r354935_pciconf.txt

13-0-amd64-r354935_pciconf.txt
Comment 11 Vinícius Zavam freebsd_committer 2019-11-25 09:35:23 UTC
root@13-0-amd64-r354935:~ # date
Mon Nov 25 09:33:27 UTC 2019

root@13-0-amd64-r354935:~ # uptime
 9:33AM  up 18 mins, 2 users, load averages: 0.05, 0.14, 0.10

ntpq> version
ntpq 4.2.8p12-a (1)

ntpq> sysinfo
associd=0 status=0613 leap_none, sync_ntp, 1 event, spike_detect,
system peer:        zarkon.mcl.gg:123
system peer mode:   client
leap indicator:     00
stratum:            3
log2 precision:     -23
root delay:         42.766
root dispersion:    756.559
reference ID:       94.16.113.67
reference time:     e1861e40.639d7150  Mon, Nov 25 2019  9:32:48.389
system jitter:      110.350937
clock jitter:       26.918
clock wander:       0.000
broadcast delay:    -50.000
symm. auth. delay:  0.000

ntpq> lpeers
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 0.freebsd.pool. .POOL.          16 p    -   64    0    0.000    0.000   0.000
+frank.askja.de  124.216.164.14   2 u  115   64    1    2.378  549.955 329.626
+spacys.de       130.149.17.8     2 u  114   64    1   26.613  542.582 321.933
+185.90.160.100  100.10.69.89     2 u  113   64    1    5.412  553.136 328.887
+meinekiste.de   170.231.250.158  2 u  115   64    1    9.228  550.012 330.670
+245.ip-51-75-74 82.161.139.11    2 u   26   64   17   17.817  713.543 514.645
+server.spnr.de  124.216.164.14   2 u   47   64   73   25.461  667.287 492.443
*zarkon.mcl.gg   131.188.3.222    2 u   53   64   77   35.762  650.561 439.307
+hotel.zq1.de    161.62.157.173   3 u   46   64   77   30.966  666.341 453.826
Comment 12 Vinícius Zavam freebsd_committer 2019-11-25 15:05:47 UTC
using pkg's ntp package didn't workaround the issue; ntp-4.2.8p13_5
Comment 13 Vinícius Zavam freebsd_committer 2019-11-25 17:44:28 UTC
openntpd-6.2p3_4,2

% ntpctl -s all
4/4 peers valid, constraint offset 0s, clock unsynced, clock offset is 536.865ms

peer
   wt tl st  next  poll          offset       delay      jitter
62.116.130.3 from pool pool.ntp.org
    1 10  2   23s   30s       419.828ms    24.961ms    17.435ms
131.188.3.221 from pool pool.ntp.org
    1 10  1   11s   33s       386.589ms    25.516ms    17.142ms
188.68.36.203 from pool pool.ntp.org
    1 10  2   20s   30s       406.697ms    24.534ms    20.615ms
185.244.195.159 from pool pool.ntp.org
    1 10  2   24s   33s       410.479ms    23.648ms    17.262ms
Comment 14 Vinícius Zavam freebsd_committer 2019-11-25 17:49:48 UTC
chrony-3.5

chronyc> tracking
Reference ID    : 8AC95ABD (ns1.your-ns.de)
Stratum         : 3
Ref time (UTC)  : Mon Nov 25 17:48:09 2019
System time     : 0.976312995 seconds slow of NTP time
Last offset     : -0.117800929 seconds
RMS offset      : 0.117547080 seconds
Frequency       : 0.000 ppm slow
Residual freq   : +198.180 ppm
Skew            : 1000000.000 ppm
Root delay      : 0.064190254 seconds
Root dispersion : 64.806434631 seconds
Update interval : 64.7 seconds
Leap status     : Normal
Comment 15 Cy Schubert freebsd_committer 2019-11-25 21:08:13 UTC
Read this carefully. There are a number of outputs being requested here.

Your network or upstream has issues. Compare offset and jitter of the server that has the error with the server that does not. You've only been able to reach once (or 7 times). Compere this with those that work.

Can we have output of cat /var/db/ntp/ntp.drift please? Large drift in conjunction with the inability to contact each ntp sever is the cause of this error.

You should see synchronization flags (*, #, +, -) in your ntpq output. We see none. You're not synchronizing. Again, this points to probable problems with either your local network, upstream, or denied by your firewall.

----

Try adding rlimit memlock 32 to ntp.conf. (This will not work with ASLR enabled.) This was the only change to ntp prior to r354367. (With ASLR enabled, mlock() caused a segfault and stack corruption.)

How much RAM is installed on this machaine? How much swap is configured? How much swap is in use?

----

Please answer all of the questions above. Again:

1. Can you ping your ntp servers? What is the round trip time?
2. Is UDP/123 open?
3. What is in ntp.drift?
4. How much RAM is in the machine?
5. Is swap being used and is ntpd using some of that swap?
6. Does setting memlock in ntp.conf do anything for you?
Comment 16 Vinícius Zavam freebsd_committer 2019-11-25 22:12:57 UTC
(In reply to Cy Schubert from comment #15)

hey, thanks for sharing some thoughts here cy@. appreciated!

I'm curious to check and understand how you meant that it's a network issue; as other machines running in the same network sync their clock waaaaay faster and with no issues like this one reported here. would really like to dig more into it.

the ntp.drift was posted on "Comment 5": its value was 48.229 after 1d18h of uptime with ntpd running.

"Comment 1" has the output of two of the ntp servers that I use to synchonize this ntpd instance. AFAIK, both are running fine - ntp1 is on the same network as the problematic machine.

at the end of the initial report you can see the flags, just like on Comments 7 and 11 - they are from the same machine (once running stable/12, later running head).

so, as I do have a very identical box to use it was moved to a different location and I cloned the system from the original server and had the same issue in another location (free of firewalling though); when I boot 12.1-RELEASE it just works as expected.

-----

1. yes; min/avg/max/mdev = 0.119/0.216/0.284/0.057 ms
2. yes;
3. 48.229 (posted before);
4. 32G;
5. no;
6. did not change a thing, used default (FreeBSD's) ntp.conf during tests only.
Comment 17 Cy Schubert freebsd_committer 2019-11-26 03:47:51 UTC
I assume you restarted ntpd after setting rlimit memlock 32 ?
Comment 18 Cy Schubert freebsd_committer 2019-11-26 04:08:44 UTC
1. Stop ntpd.

2. tcpdump -i YOUR_EXTERNAL_INTERFACE udp port 123

    or if you prefer not to post here

2. tcpdump -i YOUR_EXTERNAL_INTERFACE -w ntp.pcap udp port 123

   and email the output file to my freebsd.org email address (I'll review using wireshark)

3. start ntpd

4. Then either post the output or email the file to me. I suspect ntpd is sending but not receiving.
Comment 19 Vinícius Zavam freebsd_committer 2019-11-26 09:47:54 UTC
(In reply to Cy Schubert from comment #17)

I did not test it. I used only default ntp.conf shipped with FreeBSD without any changes. but yes, if I change the ntp.conf I do restart its daemon right after :)

forgot to mention one thing though: what I did try was changing 'kern.timecounter.hardware' to other values instead os just TSC.

I am working here to get a side-by-side scenario with 2 machines before starting the tcpdump - still curious why: the machine works fine when I run releng/12.1 as I mentioned before

thanks!
Comment 20 Vinícius Zavam freebsd_committer 2019-11-26 10:58:26 UTC
I'm running 'tcpdump' and playing with 2 different machines, both running HEAD/amd64 r354935. one is the R440 (bad guy) and the other one is just a regular PC.

the other R440 I left running with stable/12 r354893 for a couple of days has these information to share:



% uptime
11:50AM  up 5 days, 18:22, 1 user, load averages: 0.27, 0.24, 0.24

% cat /var/db/ntp/ntpd.drift
80.938

% ntpq -4 -n -p
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 10.0.5.3        134.130.4.17     2 u   59   64    1    0.338  311.293   0.000
 10.0.5.4        192.87.106.2     2 u    8   64    1    0.182  420.868  78.854
 10.0.32.248     134.130.4.17     2 u   60   64    1    1.105  307.941   0.000
 10.0.32.249     192.87.106.2     2 u   10   64    1    0.980  416.475  77.317

here we do not see the flags, but if I try to get the peers list from ***other servers*** (also running FreeBSD) in the very same network and using the very same ntp.conf, we have the following:



12.1-RELEASE-p1% ntpq -4 -n -p 
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
*10.0.5.3        134.130.4.17     2 u  121 1024  377    0.650    0.747   0.460
+10.0.5.4        192.87.106.2     2 u  627 1024  377    0.560   -0.909   0.834
-10.0.32.248     134.130.4.17     2 u   37 1024  377    2.279   -0.666   3.731
+10.0.32.249     192.87.106.2     2 u  487 1024  377    1.602   -0.848   0.955



12.1-STABLE-r352727% ntpq -4 -n -p
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
*10.0.5.3        134.130.4.17     2 u   99  128  377    0.081    0.315   0.232
+10.0.5.4        192.87.106.2     2 u  111  128  377    0.150   -1.349   0.132
+10.0.32.248     134.130.4.17     2 u    5  128  377    0.889   -0.554   7.056
-10.0.32.249     192.87.106.2     2 u   12  128  377    0.888   -1.363   1.518
Comment 21 Vinícius Zavam freebsd_committer 2019-11-26 11:58:27 UTC
Created attachment 209450 [details]
STABLE_12_r354893_ntpd.log

attaching the ntpd.log from yesterday, which is running for about 5 days.
Comment 22 Vinícius Zavam freebsd_committer 2019-11-26 12:11:09 UTC
booted an USB memstick and let it run for a while, using all the defaults we have shipped with the live/install image:

root@HEADamd64r354935-a:~ # uptime
12:08PM  up  3:18, 2 users, load averages: 0.17, 0.25, 0.24

root@HEADamd64r354935-a:~ # grep \$FreeBSD /etc/ntp.conf
# $FreeBSD: head/usr.sbin/ntp/ntpd/ntp.conf 352304 2019-09-13 20:20:05Z cy $

root@HEADamd64r354935-a:~ # grep -v -E '^#|^$' /etc/ntp.conf 
tos minclock 3 maxclock 6
pool 0.freebsd.pool.ntp.org iburst
restrict default limited kod nomodify notrap noquery nopeer
restrict source  limited kod nomodify notrap noquery
restrict 127.0.0.1
restrict ::1
leapfile "/var/db/ntpd.leap-seconds.list"

root@HEADamd64r354935-a:~ # cat /var/db/ntp/ntpd.drift
500.000

root@HEADamd64r354935-a:~ # ntpq -4 -n -p
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 0.freebsd.pool. .POOL.          16 p    -   64    0    0.000    0.000   0.000
+116.203.209.35  237.17.204.95    2 u   39   64    3    7.661  844.631 295.042
+80.67.16.8      131.188.3.221    2 u   38   64    3    1.761  1420.93 511.244
+144.76.70.233   152.103.15.66    2 u   37   64    3    9.098  1189.64 313.973
+193.30.120.245  192.53.103.108   2 u   36   64    3    7.786  847.167 298.156
+203.107.6.88    10.137.38.86     2 u   22   64    3  364.706  1125.61 289.341
+195.46.37.22    194.146.251.101  2 u    7   64    3   33.843  904.179 301.022
*213.136.0.252   .PPS.            1 u    9   64    3    6.729  1011.97 254.233
+163.237.218.19  .GPS.            1 u    5   64    3   98.093  1249.28 299.505
+188.125.64.6    212.82.106.33    2 u    3   64    3   23.957  1252.51 329.107
+85.195.227.162  124.216.164.14   2 u   66   64    3    9.857  795.025 292.792
+185.17.70.106   162.23.41.55     2 u    5   64    3   14.402  1136.51 264.795
+193.140.100.40  160.45.10.8      2 u    4   64    3   62.183  1136.77 266.951

root@HEADamd64r354935-a:~ # nc -nzvu 85.195.227.162 123
Connection to 85.195.227.162 123 port [udp/*] succeeded!

root@HEADamd64r354935-a:~ # nc -nzvu 163.237.218.19 123
Connection to 163.237.218.19 123 port [udp/*] succeeded!

root@HEADamd64r354935-a:~ # nc -nzvu 131.188.3.221 123
Connection to 131.188.3.221 123 port [udp/*] succeeded!
Comment 23 Vinícius Zavam freebsd_committer 2019-11-26 12:14:54 UTC
now the other machine that works (same version and rev from machine A, and same ntp.conf):

root@HEADamd64r354935-b:~ # uptime 
12:12PM  up  3:27, 2 users, load averages: 0.12, 0.14, 0.09

root@HEADamd64r354935-b:~ # cat /var/db/ntp/ntpd.drift
11.226

root@HEADamd64r354935-b:~ # ntpq -4 -n -p
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 0.freebsd.pool. .POOL.          16 p    -   64    0    0.000    0.000   0.000
+145.239.0.227   131.188.3.223    2 u   46   64  377   17.364  -14.710   1.288
+217.144.138.234 131.188.3.220    2 u   23   64  377   11.204  -14.875   2.140
-88.99.216.194   131.188.3.223    2 u    6   64  377   16.726  -14.850   5.395
-176.9.1.211     161.62.157.173   3 u  100   64  376   15.619  -16.407   7.332
*62.128.1.18     213.95.151.123   2 u   24   64  377   11.255  -15.058   6.604

root@HEADamd64r354935-b:~ # nc -nzvu 88.99.216.194 123
Connection to 88.99.216.194 123 port [udp/*] succeeded!

root@HEADamd64r354935-b:~ # nc -nzvu 217.144.138.234 123
Connection to 217.144.138.234 123 port [udp/*] succeeded!
Comment 24 Vinícius Zavam freebsd_committer 2019-11-26 12:17:34 UTC
netcat from my workstation to both machines (first machine A, than machine B):

% nc -nzvu 10.0.86.163 123
Connection to 10.0.86.163 123 port [udp/*] succeeded!

% nc -nzvu 10.0.128.203 123
Connection to 10.0.128.203 123 port [udp/*] succeeded!

PS: mailed you the tcpdump from both machines
Comment 25 Cy Schubert freebsd_committer 2019-11-26 13:10:05 UTC
Looking at tcpdump outputs before I go to $JOB, I'll put this here so you can check this out:

10.0.128.203 and 10.0.86.163 are serving up garbage. The NTP packets say they are stratum 0 time servers (unspecified or invalid) and their reference, origin, and receive timestamps are Feb 7, 2036 (the fields are 0's).

What are the A and B servers IP's again?
Comment 26 Vinícius Zavam freebsd_committer 2019-11-26 13:39:30 UTC
(In reply to Cy Schubert from comment #25)

10.0.86.163 == a
10.0.128.203 == b
Comment 27 Vinícius Zavam freebsd_committer 2019-11-26 13:44:38 UTC
both, A and B, are using 'pool 0.freebsd.pool.ntp.org' and are not meant to really work as NTP servers, just use ntp as client - like the default ntp.conf we have right now (Comment 22).

the actual NTP servers I have are all working just fine though.
Comment 28 Cy Schubert freebsd_committer 2019-11-26 13:54:49 UTC
That doesn't explain why you are being served up bad time by the servers in your 10.0 network. That's your problem. Fix that and your problem is fixed.

0.freebsd.pool.ntp.org does not contain 10.0 servers in its definition. YOur ntp.conf from reply #1 does not include 0.freebsd.pool.ntp.org:

restrict default limited kod nomodify notrap noquery nopeer
restrict 127.0.0.1 mask 255.255.255.255
restrict 10.64.35.0 mask 255.255.255.248 nomodify notrap
server ntp1 iburst prefer
server ntp2 iburst prefer
server ntp3 iburst
server ntp4 iburst
tos orphan 3
statistics clockstats cryptostats loopstats peerstats rawstats sysstats
Comment 29 Vinícius Zavam freebsd_committer 2019-11-26 14:08:31 UTC
in total, I have 3 machines: 2 are R440 (which are impacted with this issues to synchronize time) and 1 is just an offset box.

machine X is 10.0.5.7 (running since 5 days, with NTP sync issues);
machine A is 10.0.86.163 (very same hw as machine X, live img running);
machine B is 10.0.128.203 (offset box, live img running).

ntp servers 1, 2, 3, and 4 are fine: 2 of them are on 10.0.5.x, and 2 are on 10.0.248.x. no issues at all. these are the current internal stratum 2 servers.

machines X and A can't work as expected and use ntpd to synchronize their clocks; as we see here the drifts are kinda high, offset and jitter are pretty bad although the delay/latency to reach internal and external NTP servers is not a problem.

hope that gives all a better picture of the scenario here. maybe I should have written it before.
Comment 30 Vinícius Zavam freebsd_committer 2019-11-26 14:13:01 UTC
(In reply to Cy Schubert from comment #28)

no no no. this config you pasted is definitely *NOT* used to sync against pool.ntp.org!

the actual ntp.conf for internal use is:

-----
restrict        default limited kod nomodify notrap noquery nopeer
restrict        127.0.0.1 mask 255.255.255.255
restrict        10.0.0.0  mask 255.255.0.0     nomodify notrap
restrict        10.64.0.0 mask 255.255.0.0     nomodify notrap
server  ntp1       iburst prefer
server  ntp2       iburst prefer
server  ntp3       iburst # prefer
server  ntp4       iburst # prefer
tos     orphan  3
-----

the 'statistics' was added just to collect data; the restrict was modified before but THIS ONE is the one used in prod for this environment
Comment 31 Vinícius Zavam freebsd_committer 2019-11-26 14:37:09 UTC
current test setup now on machine A and B: both bare metal with live images running HEAD amd64 r354935.

# ntp.conf
tos minclock 3 maxclock 6
pool 0.freebsd.pool.ntp.org iburst
restrict default limited kod nomodify notrap noquery nopeer
restrict source  limited kod nomodify notrap noquery
restrict 127.0.0.1
restrict ::1
leapfile "/var/db/ntpd.leap-seconds.list"

after getting network to work, just ran

# service ntpd onestart
Comment 32 Vinícius Zavam freebsd_committer 2019-11-26 14:49:07 UTC
short update on the 'ntpq -p' for machine A and B (with their flags):
----------

root@HEADamd64r354935-a:~ # uptime
 2:45PM  up  5:55, 2 users, load averages: 0.17, 0.28, 0.27

root@HEADamd64r354935-a:~ # ntpq -4 -n -p 
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 0.freebsd.pool. .POOL.          16 p    -   64    0    0.000    0.000   0.000
#82.100.248.10   194.97.129.17    2 u   54   64    1    4.631  528.815 222.540
+131.234.137.63  .DCF.            1 u   50   64    1   13.021  881.310 243.876
#138.201.16.225  130.149.17.21    2 u   50   64    1    9.245  532.426 226.107
#5.189.146.13    131.188.3.220    2 u   50   64    1   14.836  655.488 141.082
#176.9.166.35    192.53.103.108   2 u   34   64    1    9.306  685.282 147.836
#193.30.120.245  192.53.103.108   2 u   16   64    1    7.779  943.407 268.613
+173.249.58.145  131.188.3.222    2 u   12   64    1   15.856  951.403 270.882
+37.120.184.82   131.188.3.222    2 u   56   64    1    7.635  869.279 239.843
+188.68.36.203   131.188.3.221    2 u   57   64    1    7.623  752.591 142.400
+80.67.16.8      3.121.254.221    3 u   58   64    1    1.762  754.617 142.360
+213.239.239.166 237.17.204.95    2 u   57   64    1    9.279  756.224 146.244
*5.199.135.170   130.149.17.21    2 u   56   64    1    2.139  868.705 239.148

root@HEADamd64r354935-a:~ # cat /var/db/ntp/ntpd.drift 
500.000
----------

root@HEADamd64r354935-b:~ # uptime
 2:46PM  up  6:01, 2 users, load averages: 0.10, 0.14, 0.09

root@HEADamd64r354935-b:~ # ntpq -4 -n -p 
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 0.freebsd.pool. .POOL.          16 p    -   64    0    0.000    0.000   0.000
+178.162.199.162 131.188.3.223    2 u   15  128  377   20.890   -9.873  26.352
+144.76.0.164    193.67.79.202    2 u    1  128  377   16.949   -9.525   2.543
*90.187.99.165   .PPS.            1 u  123  128  377   32.826  -12.698   2.729
+217.91.44.17    192.168.100.15   2 u  117  128  377   23.217  -10.839   3.000
+80.153.195.191  192.168.100.9    2 u  124  128  377   25.459   -7.415   2.383

root@HEADamd64r354935-b:~ # cat /var/db/ntp/ntpd.drift 
6.134
Comment 33 Vinícius Zavam freebsd_committer 2019-11-26 14:54:46 UTC
regarding the comments about "network issues": how would that explain a pretty normal behavior of NTP running 12.1-RELEASE on the machine A (on the very same network)?
Comment 34 Cy Schubert freebsd_committer 2019-11-26 20:14:29 UTC
After briefly looking at the pcap files you sent me, it's not a network issue but the ntp servers on your 10.0 network are serving bad time. They say they are stratum 0 time servers, which is invalid and the three time fields in the ntp packets are zero.

The ntpq -p from your A and B servers look good.
Comment 35 Vinícius Zavam freebsd_committer 2019-11-27 09:52:36 UTC
(In reply to Cy Schubert from comment #34)

% host ntp
ntp.localdomain has address 10.0.5.4
ntp.localdomain.com has address 10.0.32.249
ntp.localdomain.com has address 10.0.32.248
ntp.localdomain.com has address 10.0.5.3

% ntpdate -q ntp
server 10.0.5.4, stratum 2, offset -0.000039, delay 0.02678
server 10.0.32.249, stratum 2, offset 0.000023, delay 0.02589
server 10.0.32.248, stratum 2, offset -0.000080, delay 0.02583
server 10.0.5.3, stratum 2, offset -0.000569, delay 0.02702
27 Nov 09:43:16 ntpdate[11451]: adjust time server 10.0.32.248 offset -0.000080 sec
-----

% ntpq -4 -n -p ntp1
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
-81.173.193.222  131.188.3.220    2 u  979 1024  377    1.343    2.425   0.145
-81.173.193.223  193.67.79.202    2 u  736 1024  377    1.176    1.530   0.307
*134.130.4.17    .GPS.            1 u  890 1024  377    2.168    0.380   0.305
+134.130.5.17    .GPS.            1 u  808 1024  377    2.055    0.293   0.369
+129.143.2.23    .GPS.            1 u  352 1024  377    7.571    0.311   0.302
+129.143.2.33    .PZF.            1 u  811 1024  377    7.481    0.196   0.192
-194.109.6.2     193.79.237.14    2 u  293 1024  377    5.773    0.022   0.277
+213.136.0.252   .PPS.            1 u  962 1024  377    6.243    0.202   0.511
+192.53.103.103  .PTB.            1 u  927 1024  377   10.518    0.404   1.809
-10.0.5.4        192.87.106.2     2 s  349 1024  337    0.183    0.729   0.162

% ntpq -4 -n -p ntp2
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
-81.173.193.222  130.149.17.21    2 u  416 1024  377    1.172    1.517   0.120
-81.173.193.223  193.67.79.202    2 u  726 1024  377    1.031    0.762   0.294
+134.130.4.17    .GPS.            1 u  255 1024  377    2.217   -0.387   0.176
+134.130.5.17    .GPS.            1 u  718 1024  377    2.150   -0.310   0.104
-129.143.2.23    .GPS.            1 u  149 1024  377    7.572   -0.480   0.180
-129.143.2.33    .PZF.            1 u  852 1024  377    7.477   -0.650   0.218
-194.109.6.2     193.67.79.202    2 u  568 1024  377    5.456   -0.565   0.046
*192.87.106.2    .GPS.            1 u  542 1024  377    5.897   -0.054   0.100
+192.87.36.4     .MRS.            1 u   36 1024  377    8.288   -0.209   0.210
-10.0.5.3        134.130.4.17     2 s  367 1024  176    0.066   -0.670   0.205

% ntpq -4 -n -p ntp3
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
-81.173.193.222  131.188.3.220    2 u  961 1024  377    1.851    1.497   0.454
-81.173.193.223  193.67.79.202    2 u  102 1024  377    1.499    0.702   2.060
*134.130.4.17    .GPS.            1 u  489 1024  377    2.481   -0.365   4.585
+134.130.5.17    .GPS.            1 u  912 1024  377    2.419   -0.361   0.426
+129.143.2.23    .GPS.            1 u  371 1024  377    7.941   -0.306   0.312
+129.143.2.33    .PZF.            1 u  994 1024  377    7.829   -0.547   0.330
-194.109.6.2     193.67.79.202    2 u  462 1024  377    6.535   -0.867   6.943
-213.136.0.252   .PPS.            1 u  394 1024  377    8.033   -0.973   5.084
+192.53.103.103  .PTB.            1 u  346 1024  377   10.727   -0.306   1.693
-10.0.32.249     192.87.106.2     2 s  580 1024  376    0.180    0.157   0.329

% ntpq -4 -n -p ntp4
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
-81.173.193.222  131.188.3.220    2 u  781 1024  377    2.001    1.389   6.224
-81.173.193.223  193.67.79.202    2 u  277 1024  377    1.477    0.594   1.523
+134.130.4.17    .GPS.            1 u  511 1024  377    2.537   -0.467   8.575
+134.130.5.17    .GPS.            1 u   41 1024  377    2.467   -0.515   1.370
-129.143.2.23    .GPS.            1 u  577 1024  377    7.978   -0.511   0.063
-129.143.2.33    .PZF.            1 u  376 1024  377    7.928   -0.759   2.418
-194.109.6.2     193.67.79.202    2 u  812 1024  377    6.086   -0.628   0.657
*192.87.106.2    .GPS.            1 u    3 1024  377    6.066   -0.334   0.128
+192.87.36.4     .MRS.            1 u  125 1024  377    8.419   -0.356   0.106
-10.0.32.248     134.130.4.17     2 s  316 1024  377    0.141   -0.138   0.321
-----

% ntpq -4 -n -c sysinfo ntp1
associd=0 status=0615 leap_none, sync_ntp, 1 event, clock_sync,
system peer:        134.130.4.17:123
system peer mode:   client
leap indicator:     00
stratum:            2
log2 precision:     -24
root delay:         2.050
root dispersion:    19.509
reference ID:       134.130.4.17
reference time:     e188c440.20a64f14  Wed, Nov 27 2019  9:45:36.127
system jitter:      0.495904
clock jitter:       0.264
clock wander:       0.055
broadcast delay:    -50.000
symm. auth. delay:  0.010

% ntpq -4 -n -c sysinfo ntp2
associd=0 status=0615 leap_none, sync_ntp, 1 event, clock_sync,
system peer:        192.87.106.2:123
system peer mode:   client
leap indicator:     00
stratum:            2
log2 precision:     -24
root delay:         5.897
root dispersion:    45.148
reference ID:       192.87.106.2
reference time:     e188bd76.faadd7b2  Wed, Nov 27 2019  9:16:38.979
system jitter:      0.100174
clock jitter:       0.138
clock wander:       0.013
broadcast delay:    -50.000
symm. auth. delay:  0.008

% ntpq -4 -n -c sysinfo ntp3
associd=0 status=0615 leap_none, sync_ntp, 1 event, clock_sync,
system peer:        134.130.4.17:123
system peer mode:   client
leap indicator:     00
stratum:            2
log2 precision:     -24
root delay:         2.481
root dispersion:    34.979
reference ID:       134.130.4.17
reference time:     e188c1b9.3abded05  Wed, Nov 27 2019  9:34:49.229
system jitter:      4.585486
clock jitter:       0.170
clock wander:       0.037
broadcast delay:    -50.000
symm. auth. delay:  0.000

% ntpq -4 -n -c sysinfo ntp4
associd=0 status=0615 leap_none, sync_ntp, 1 event, clock_sync,
system peer:        192.87.106.2:123
system peer mode:   client
leap indicator:     00
stratum:            2
log2 precision:     -24
root delay:         6.066
root dispersion:    21.975
reference ID:       192.87.106.2
reference time:     e188c3a1.1ddeb161  Wed, Nov 27 2019  9:42:57.116
system jitter:      0.128426
clock jitter:       0.153
clock wander:       0.014
broadcast delay:    -50.000
symm. auth. delay:  0.000
Comment 36 Vinícius Zavam freebsd_committer 2019-11-27 09:56:45 UTC
(In reply to Vinícius Zavam from comment #35)

DISCLAIMER: previous 'host' command returns

% host ntp
ntp.localdomain has address 10.0.5.4
ntp.localdomain has address 10.0.32.249
ntp.localdomain has address 10.0.32.248
ntp.localdomain has address 10.0.5.3

just replaced domain's name; let's focus on the NTP thing. DNS is definitely working!
Comment 37 Vinícius Zavam freebsd_committer 2019-11-27 10:01:06 UTC
I mailed you the pcap file which I ran in my workstation, using these 4 servers.
Comment 38 Vinícius Zavam freebsd_committer 2019-11-27 11:46:20 UTC
*** ran the "Platform Specific Bootable ISO, PER440,19.10.00" to update BIOS and other firmwares, but no updates were applied - the box is already with latest stuff. https://www.dell.com/support/home/us/en/04/drivers/driversdetails?driverid=1098x&oscode=naa&productcode=poweredge-r440 

this is machine X and A ^
Comment 39 Cy Schubert freebsd_committer 2019-11-27 20:48:18 UTC
Need a reset here:

Can you list the IP addresses of your 12.1, A and B servers, please. 

Also list ntp.conf for each.
Comment 40 Vinícius Zavam freebsd_committer 2019-11-28 14:06:12 UTC
machine X; 10.0.5.7 (stable/12@r354893, 12.1-STABLE)
machine A; 10.0.86.163 (head@r354935)
machine B; 10.0.128.203 (head@r354935)

# grep -v -E '^#|^$' /etc/ntp.conf 
tos minclock 3 maxclock 6
pool 0.freebsd.pool.ntp.org iburst
restrict default limited kod nomodify notrap noquery nopeer
restrict source  limited kod nomodify notrap noquery
restrict 127.0.0.1
restrict ::1
leapfile "/var/db/ntpd.leap-seconds.list"
Comment 41 Vinícius Zavam freebsd_committer 2019-11-29 15:11:32 UTC
(In reply to Cy Schubert from comment #25)

regarding the timestamp with 'Feb 7 2036' you mentioned before: I've tcpdumped other FreeBSD machines and they all have the same "issue".

these recently tested FreeBSD machines are not even in the same location/country, and therefore can't be influenced by the other machines/servers mentioned before.

they run the following revisions: r353654 e r354990 and r354992 (HEAD/amd64). they're all using the same default ntp.conf from FreeBSD, just like the one pasted on Comment 40.

this is how the time stamping looks like:

Network Time Protocol (NTP Version 4, client)
    Flags: 0xe3, Leap Indicator: unknown (clock unsynchronized), Version number: NTP Version 4, Mode: client
        11.. .... = Leap Indicator: unknown (clock unsynchronized) (3)
        ..10 0... = Version number: NTP Version 4 (4)
        .... .011 = Mode: client (3)
    [Response In: 2]
    Peer Clock Stratum: unspecified or invalid (0)
    Peer Polling Interval: 6 (64 seconds)
    Peer Clock Precision: 0.000000 seconds
    Root Delay: 0.000000 seconds
    Root Dispersion: 0.000000 seconds
    Reference ID: (Initialization)
    Reference Timestamp: Feb  7, 2036 06:28:16.000000000 UTC
    Origin Timestamp: Feb  7, 2036 06:28:16.000000000 UTC
    Receive Timestamp: Feb  7, 2036 06:28:16.000000000 UTC
    Transmit Timestamp: Nov 29, 2019 14:45:11.501112827 UTC
-----

Network Time Protocol (NTP Version 4, client)
    Flags: 0x23, Leap Indicator: no warning, Version number: NTP Version 4, Mode: client
        00.. .... = Leap Indicator: no warning (0)
        ..10 0... = Version number: NTP Version 4 (4)
        .... .011 = Mode: client (3)
    [Response In: 58]
    Peer Clock Stratum: secondary reference (2)
    Peer Polling Interval: 6 (64 seconds)
    Peer Clock Precision: 0.000000 seconds
    Root Delay: 0.009277 seconds
    Root Dispersion: 0.940109 seconds
    Reference ID: 76.127.35.142
    Reference Timestamp: Nov 29, 2019 14:45:18.493365262 UTC
    Origin Timestamp: Feb  7, 2036 06:28:16.000000000 UTC
    Receive Timestamp: Feb  7, 2036 06:28:16.000000000 UTC
    Transmit Timestamp: Nov 29, 2019 14:45:20.484546625 UTC
Comment 42 Vinícius Zavam freebsd_committer 2019-12-04 10:38:00 UTC
Created attachment 209680 [details]
STABLE_12_r354367_dmesg.boot.txt
Comment 44 Vinícius Zavam freebsd_committer 2019-12-04 11:55:36 UTC
the 'rlimit memlock 32' option was not added to the ntp.conf on my side because it seems to be the default already.

from the ntp.conf(5) manpage:

             memlock Nmegabytes
                     Specify the number of megabytes of memory that should be
                     allocated and locked.  Probably only available under
                     Linux, this option may be useful when dropping root (the
                     -i option).  The default is 32 megabytes on non-Linux
                     machines, and -1 under Linux.  -1 means "do not lock the
                     process into memory".  0 means "lock whatever memory the
                     process wants into memory".
Comment 45 Vinícius Zavam freebsd_committer 2019-12-04 13:29:08 UTC
Created attachment 209689 [details]
STABLE_12_r354367_ntpq_rootdisp.png

12.1-STABLE, stable/12 [r354367] is the dark blue line.

used `ntpq -4 -n -c rl` to collect data from *all* these 5 machines.
Comment 46 Cy Schubert freebsd_committer 2019-12-04 13:41:21 UTC
(In reply to Vinícius Zavam from comment #44)
rlimit memlock 32 is not the default. It was removed last summer because it caused ntp to segfault with ASLR and stack gap != 0. There was a discussion about this on -current at the time.
Comment 47 Cy Schubert freebsd_committer 2019-12-04 13:42:39 UTC
Added Harlan Stenn of ntp.org to this discussion.
Comment 48 Vinícius Zavam freebsd_committer 2019-12-04 13:55:57 UTC
(In reply to Cy Schubert from comment #46)

oh, so... we could update the manpage; I might take a time to patch it later if we need to. thanks for reporting it - I missed that thread. 

I am going to add it to the .conf and restart the daemon. thanks!
Comment 49 Vinícius Zavam freebsd_committer 2019-12-04 14:21:02 UTC
same.

% ntpdate -4 -q -d 10.0.5.7
 4 Dec 14:19:20 ntpdate[14809]: ntpdate 4.2.8p12-a (1)
transmit(10.0.5.7)
receive(10.0.5.7)
10.0.5.7: Server dropped: strata too high

server 10.0.5.7, port 123
stratum 16, precision -22, leap 11, trust 000
refid [STEP], root delay 0.000000, root dispersion 0.000519
reference time:      (no time)
originate timestamp: e1923ee7.37e78eb9  Wed, Dec  4 2019 14:19:19.218
transmit timestamp:  e1923ee8.24faa500  Wed, Dec  4 2019 14:19:20.144
delay 0.02658, dispersion 0.00000, offset -0.926634

 4 Dec 14:19:20 ntpdate[14809]: no server suitable for synchronization found

% ntpq -4 -n -c rl 10.0.5.7
associd=0 status=c018 leap_alarm, sync_unspec, 1 event, no_sys_peer,
version="ntpd 4.2.8p12-a (1)", processor="amd64",
system="FreeBSD/12.1-STABLE", leap=11, stratum=16, precision=-22,
rootdelay=0.000, rootdisp=0.780, refid=STEP, reftime=(no time),
clock=e1923ef9.0dc12b58  Wed, Dec  4 2019 14:19:37.053, peer=0, tc=6,
mintc=3, offset=0.000000, frequency=128.357, sys_jitter=0.000238,
clk_jitter=0.000, clk_wander=0.000, tai=37, leapsec=201701010000,
expire=202006280000
Comment 50 Vinícius Zavam freebsd_committer 2019-12-04 14:52:25 UTC
booted the FreeBSD-12.1-STABLE-amd64-20191127-r355118-mini-memstick.img and performed `service ntpd onestart` (after getting a work network connection, of course) and was presented to the very same behavior :"(

https://download.freebsd.org/ftp/snapshots/amd64/amd64/ISO-IMAGES/12.1/FreeBSD-12.1-STABLE-amd64-20191127-r355118-mini-memstick.img
Comment 51 Vinícius Zavam freebsd_committer 2019-12-06 10:09:28 UTC
I am adding a few outputs here from truss and ktrace, which I ran in a FreeBSD HEAD@r355121 (amd64 bare metal hardware; dell poweredge r440, as reported before)

https://share.riseup.net/#lzApqrgFltk9J4rlH11Zdg
>>> freebsd-head-r355121-amd64_ktrace_output_SERVICE_ntpd_ONESTART.bin

https://share.riseup.net/#LVlKzFFoHiylOMkfu58xng
>>> ktrace_output_ntpq.bin

https://share.riseup.net/#SQCa-pCEZmTi2wB4nX8O1Q
>>> freebsd-head-r355121-amd64_truss_output_SERVICE_ntpd_ONESTART.txt

https://share.riseup.net/#Dk9Kn_Wipb-aXNkN6l-BYA
>>> truss_output_ntpq.txt
Comment 52 Vinícius Zavam freebsd_committer 2019-12-06 10:46:51 UTC
% ntpq -4 -n -c rl -wp 127.0.0.1
associd=0 status=c613 leap_alarm, sync_ntp, 1 event, spike_detect,
version="ntpd 4.2.8p12-a (1)", processor="amd64",
system="FreeBSD/13.0-CURRENT", leap=11, stratum=3, precision=-23,
rootdelay=17.795, rootdisp=1311.617, refid=213.239.239.164,
reftime=e194ad60.0e89a5e8  Fri, Dec  6 2019 10:35:12.056,
clock=e194aeb2.99e66d49  Fri, Dec  6 2019 10:40:50.601, peer=14176, tc=6,
mintc=3, offset=0.000000, frequency=500.000, sys_jitter=173.114733,
clk_jitter=0.000, clk_wander=0.000, tai=37, leapsec=201701010000,
expire=201912280000

     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 0.freebsd.pool.ntp.org
                 .POOL.          16 p    -   64    0    0.000    0.000   0.000
+195.50.171.101  192.53.103.108   2 u   49   64    7    5.545  580.506 382.202
+35.158.196.249  192.53.103.108   2 u   51   64    7    4.671  576.939 382.105
#5.9.121.21      131.188.3.222    2 u   44   64    7    9.112  585.911 382.935
#78.46.241.151   213.239.239.165  3 u   49   64    7    9.312  454.438 479.780
+81.7.16.52      237.17.204.95    2 u   30   64    7   18.855  736.585 321.421
#94.16.114.254   5.9.121.21       3 u   21   64    7    7.765  869.343 305.652
#144.76.96.7     205.46.178.169   2 u   13   64    7    9.029  460.459 528.144
+193.141.27.6    192.53.103.108   2 u   14   64    7    6.719  872.974 303.831
#144.76.59.37    195.145.119.188  2 u   49   64    7    9.213  452.879 480.766
+159.69.150.81   237.17.204.95    2 u   46   64    7    7.735  809.909 292.674
+136.243.7.20    0.242.242.75     3 u   18   64    7    9.098  750.452 325.521
*213.239.239.164 205.46.178.169   2 u   16   64   17    7.723  1215.27 493.678

KTRACE: https://share.riseup.net/#0ZHiHkGHnc7rBcWTenvmeQ
TRUSS: https://share.riseup.net/#MtAe5XFYrG81DV_MCUHMOQ

root@freebsd-head-r355121-amd64:~ # grep -E -v '^$|^#' /etc/ntp.conf 
tos minclock 3 maxclock 6
pool 0.freebsd.pool.ntp.org iburst
restrict default limited kod nomodify notrap noquery nopeer
restrict source  limited kod nomodify notrap noquery
restrict 127.0.0.1
restrict ::1
leapfile "/var/db/ntpd.leap-seconds.list"
Comment 53 Vinícius Zavam freebsd_committer 2019-12-06 10:50:26 UTC
# ntpdate -4 -q -d 127.0.0.1
 6 Dec 10:45:11 ntpdate[3328]: ntpdate 4.2.8p12-a (1)
transmit(127.0.0.1)
receive(127.0.0.1)
127.0.0.1: Server dropped: leap not in sync

server 127.0.0.1, port 123
stratum 3, precision -23, leap 11, trust 000
refid [144.76.59.37], root delay 0.017899, root dispersion 2.040878
reference time:      e194afb0.dc30c0aa  Fri, Dec  6 2019 10:45:04.860
originate timestamp: e194afb7.7c01ea59  Fri, Dec  6 2019 10:45:11.484
transmit timestamp:  e194afb7.7bf25b56  Fri, Dec  6 2019 10:45:11.484
delay 0.02589, dispersion 0.00000, offset 0.000051

 6 Dec 10:45:11 ntpdate[3328]: no server suitable for synchronization found
----------

# ntpdate -4 -q -d 127.0.0.1
 6 Dec 10:45:36 ntpdate[3329]: ntpdate 4.2.8p12-a (1)
transmit(127.0.0.1)
receive(127.0.0.1)
127.0.0.1: Server dropped: leap not in sync

server 127.0.0.1, port 123
stratum 3, precision -23, leap 11, trust 000
refid [5.9.121.21], root delay 0.017548, root dispersion 2.071915
reference time:      e194afb4.d40dab7a  Fri, Dec  6 2019 10:45:08.828
originate timestamp: e194afd0.d54ad348  Fri, Dec  6 2019 10:45:36.833
transmit timestamp:  e194afd0.d5431d47  Fri, Dec  6 2019 10:45:36.833
delay 0.02573, dispersion 0.00000, offset -0.000005

 6 Dec 10:45:36 ntpdate[3329]: no server suitable for synchronization found
----------

https://share.riseup.net/#B_i8WV9SfSUSEJpRCun5rw
>>> ktrace -d -i -f /var/my_ntpd/ktrace_output_ntpq.txt 

https://share.riseup.net/#Ox3sAwTrZUjdCWrbu11djQ
>>> truss -o /var/my_ntpd/truss_output_ntpq.txt -a -f -d -D -e -H
Comment 54 Cy Schubert freebsd_committer 2019-12-06 20:48:38 UTC
(In reply to Cy Schubert from comment #46)
I've already updated the base version file and the man pages in base and the ports. There is no sense submitting patches.
Comment 55 Vinícius Zavam freebsd_committer 2019-12-09 08:26:03 UTC
(In reply to Cy Schubert from comment #54)

https://svnweb.freebsd.org/base/head/contrib/ntp/ntpd/ntp.conf.5man?view=markup#l3106

it still points out that 32mb is the default for non-Linux systems. so, upstream might be getting a patch for that or I just do not follow?
Comment 56 Cy Schubert freebsd_committer 2019-12-09 12:44:05 UTC
(In reply to Vinícius Zavam from comment #55)
See src r355388 and ports r519022.
Comment 57 Vinícius Zavam freebsd_committer 2019-12-09 13:54:39 UTC
(In reply to Cy Schubert from comment #56)

my bad though. sorry, I looked under /contrib/ntp instead of /usr/sbin/ntp. thanks!
Comment 58 Vinícius Zavam freebsd_committer 2019-12-09 13:55:55 UTC
(In reply to Vinícius Zavam from comment #57)

I meant to write 'base/usr.sbin/ntp' here (sorry for all the SPAM, just want to clarify)
Comment 59 Cy Schubert freebsd_committer 2019-12-09 20:50:13 UTC
I've asked our upstream ntp.org to look at this PR.  They have asked
about the packets in your rawstats file that contain the "Unexpected
origin timestamp 0xe180e455.d15bf3fb".  They say that the message you
see indicates that you are getting a 2nd incoming packet with the same
origin timestamp, and this message is alerting you to this situation.
Whether or not this PR is valid depends on what's going on with the root
cause of your "Unexpected origin timestamp" message.
Comment 60 Vinícius Zavam freebsd_committer 2019-12-10 10:15:23 UTC
(In reply to Cy Schubert from comment #59)

I will start the test scenario again (using the memstick live image) and collect you these stats. by the end of the day I should mail them to you. 

thanks!
Comment 61 Vinícius Zavam freebsd_committer 2019-12-10 12:54:48 UTC
(In reply to Cy Schubert from comment #59)

incoming.