RE: [chrony-dev] Chrony 2.0-pre1 fails on FreeBSD 10.1

[ Thread Index | Date Index | More chrony.tuxfamily.org/chrony-dev Archives ]


I have recompiled chrony with --enable-debug.
It seems the initial 'initstepslew' received data, but afterwards no data is received.
The relevant lines in chrony.conf are:

server tt52.ripe.net iburst maxdelayratio 2 polltarget 8
initstepslew 0.1 chime1.surfnet.nl chime2.surfnet.nl chime4.surfnet.nl chime5.surfnet.nl chime6.surfnet.nl

This is the debug output from chronyd -d -d:

2015-01-29T10:46:44Z main.c:433:(main) chronyd version 2.0-pre1 starting (+CMDMON +NTP +REFCLOCK -RTC -PRIVDROP +DEBUG +ASYNCDNS +IPV6 -SECHASH)
2015-01-29T10:46:45Z local.c:138:(calculate_sys_precision) Clock precision 0.000002000 (-19)
2015-01-29T10:46:45Z local.c:574:(lcl_RegisterSystemDrivers) Local freq=0..000ppm
2015-01-29T10:46:45Z sys_sunos.c:347:(setup_kernel) Cannot write to _dosynctodr
2015-01-29T10:46:45Z keys.c:191:(determine_hash_delay) authentication delay for key 1: 3 useconds
2015-01-29T10:46:45Z reference.c:193:(REF_Initialise) Frequency -10.016 +/- 0.052 ppm read from /var/db/chrony.drift
2015-01-29T10:46:46Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.106.2:123]
2015-01-29T10:46:46Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.106..2:123 from [UNSPEC] fd 7
2015-01-29T10:46:46Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 192.87.106.2:123 to [UNSPEC] fd 7
2015-01-29T10:46:46Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=2 poll=6 prec=-19 root_delay=0.001068 root_disp=0.026138 refid=c0576a03 []
2015-01-29T10:46:46Z ntp_core.c:1282:(receive_packet) reference=1422527685.662032 origin=1422528406.192338 receive=1422528406.194197 transmit=1422528406.194333
2015-01-29T10:46:46Z ntp_core.c:1284:(receive_packet) offset=0.000450 delay=0.002819 dispersion=0.000008 root_delay=0.003887 root_dispersion=0.026146
2015-01-29T10:46:46Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:46Z sources.c:356:(SRC_AccumulateSample) ip=[192.87.106.2] t=1422528406.193815 ofs=-0.000450 del=0.003887 disp=0.026146 str=2
2015-01-29T10:46:46Z sourcestats.c:582:(SST_GetSelectionData) n=1 off=-0.000450 dist=0.028093 var=16.000000 first_ago=0.001478 last_ago=0.001478 selok=0
2015-01-29T10:46:46Z sources.c:695:(SRC_SelectSource) badstat=5 sel=0 badstat_reach=1 sel_reach=0 max_reach_ago=0.000000
2015-01-29T10:46:46Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [194.171.167.130:123]
2015-01-29T10:46:46Z ntp_io.c:679:(send_packet) Sent 48 bytes to 194.171.167.130:123 from [UNSPEC] fd 7
2015-01-29T10:46:46Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 194.171.167.130:123 to [UNSPEC] fd 7
2015-01-29T10:46:46Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-18 root_delay=0.000000 root_disp=0.000320 refid=50505300 []
2015-01-29T10:46:46Z ntp_core.c:1282:(receive_packet) reference=1422528400.826991 origin=1422528406.386816 receive=1422528406.390379 transmit=1422528406.390666
2015-01-29T10:46:46Z ntp_core.c:1284:(receive_packet) offset=0.000146 delay=0.006834 dispersion=0.000016 root_delay=0.006834 root_dispersion=0.000337
2015-01-29T10:46:46Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:46Z sources.c:356:(SRC_AccumulateSample) ip=[194.171.167..130] t=1422528406.390376 ofs=-0.000146 del=0.006834 disp=0.000337 str=1
2015-01-29T10:46:46Z sourcestats.c:582:(SST_GetSelectionData) n=1 off=-0.000450 dist=0.028490 var=16.000000 first_ago=0.200121 last_ago=0.200121 selok=0
2015-01-29T10:46:46Z sourcestats.c:582:(SST_GetSelectionData) n=1 off=-0.000146 dist=0.003761 var=16.000000 first_ago=0.003560 last_ago=0.003560 selok=0
2015-01-29T10:46:46Z sources.c:695:(SRC_SelectSource) badstat=5 sel=0 badstat_reach=1 sel_reach=0 max_reach_ago=0.000000
2015-01-29T10:46:46Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.36.4:123]
2015-01-29T10:46:46Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.36.4:123 from [UNSPEC] fd 7
2015-01-29T10:46:46Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 192.87.36.4:123 to [UNSPEC] fd 7
2015-01-29T10:46:46Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-19 root_delay=0.000000 root_disp=0.000275 refid=47505300 []
2015-01-29T10:46:46Z ntp_core.c:1282:(receive_packet) reference=1422528404.225578 origin=1422528406.583235 receive=1422528406.586308 transmit=1422528406.586443
2015-01-29T10:46:46Z ntp_core.c:1284:(receive_packet) offset=0.000104 delay=0.005938 dispersion=0.000014 root_delay=0.005938 root_dispersion=0.000289
2015-01-29T10:46:46Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:46Z sources.c:356:(SRC_AccumulateSample) ip=[192.87.36.4] t=1422528406.586271 ofs=-0.000104 del=0.005938 disp=0.000289 str=1
2015-01-29T10:46:46Z sourcestats.c:582:(SST_GetSelectionData) n=1 off=-0.000450 dist=0.028881 var=16.000000 first_ago=0.395493 last_ago=0.395493 selok=0
2015-01-29T10:46:46Z sourcestats.c:582:(SST_GetSelectionData) n=1 off=-0.000104 dist=0.003264 var=16.000000 first_ago=0.003037 last_ago=0.003037 selok=0
2015-01-29T10:46:46Z sourcestats.c:582:(SST_GetSelectionData) n=1 off=-0.000146 dist=0.004151 var=16.000000 first_ago=0.198932 last_ago=0.198932 selok=0
2015-01-29T10:46:46Z sources.c:695:(SRC_SelectSource) badstat=5 sel=0 badstat_reach=1 sel_reach=0 max_reach_ago=0.000000
2015-01-29T10:46:46Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [145.145.170.84:123]
2015-01-29T10:46:46Z ntp_io.c:679:(send_packet) Sent 48 bytes to 145.145.170.84:123 from [UNSPEC] fd 7
2015-01-29T10:46:46Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.106.3:123]
2015-01-29T10:46:46Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.106..3:123 from [UNSPEC] fd 8
2015-01-29T10:46:48Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.106.2:123]
2015-01-29T10:46:48Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.106..2:123 from [UNSPEC] fd 9
2015-01-29T10:46:48Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 192.87.106.2:123 to [UNSPEC] fd 9
2015-01-29T10:46:48Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=2 poll=6 prec=-19 root_delay=0.001068 root_disp=0.026169 refid=c0576a03 []
2015-01-29T10:46:48Z ntp_core.c:1282:(receive_packet) reference=1422527685.662032 origin=1422528408.263164 receive=1422528408.264967 transmit=1422528408.265101
2015-01-29T10:46:48Z ntp_core.c:1284:(receive_packet) offset=0.000412 delay=0.002785 dispersion=0.000008 root_delay=0.003853 root_dispersion=0.026177
2015-01-29T10:46:48Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:48Z sources.c:356:(SRC_AccumulateSample) ip=[192.87.106.2] t=1422528408.264622 ofs=-0.000412 del=0.003853 disp=0.026177 str=2
2015-01-29T10:46:48Z sourcestats.c:582:(SST_GetSelectionData) n=2 off=-0.000412 dist=0.028106 var=16.000000 first_ago=2.072267 last_ago=0.001460 selok=0
2015-01-29T10:46:48Z sourcestats.c:582:(SST_GetSelectionData) n=1 off=-0.000104 dist=0.006618 var=16.000000 first_ago=1.679811 last_ago=1.679811 selok=0
2015-01-29T10:46:48Z sourcestats.c:582:(SST_GetSelectionData) n=1 off=-0.000146 dist=0.007505 var=16.000000 first_ago=1.875706 last_ago=1.875706 selok=0
2015-01-29T10:46:48Z sources.c:695:(SRC_SelectSource) badstat=5 sel=0 badstat_reach=3 sel_reach=0 max_reach_ago=0.000000
2015-01-29T10:46:48Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [194.171.167.130:123]
2015-01-29T10:46:48Z ntp_io.c:679:(send_packet) Sent 48 bytes to 194.171.167.130:123 from [UNSPEC] fd 9
2015-01-29T10:46:48Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 194.171.167.130:123 to [UNSPEC] fd 9
2015-01-29T10:46:48Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-18 root_delay=0.000000 root_disp=0.000351 refid=50505300 []
2015-01-29T10:46:48Z ntp_core.c:1282:(receive_packet) reference=1422528400.826991 origin=1422528408.427840 receive=1422528408.431301 transmit=1422528408.431598
2015-01-29T10:46:48Z ntp_core.c:1284:(receive_packet) offset=0.000226 delay=0.006471 dispersion=0.000016 root_delay=0.006471 root_dispersion=0.000366
2015-01-29T10:46:48Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:48Z sources.c:356:(SRC_AccumulateSample) ip=[194.171.167..130] t=1422528408.431223 ofs=-0.000226 del=0.006471 disp=0.000366 str=1
2015-01-29T10:46:48Z sourcestats.c:582:(SST_GetSelectionData) n=2 off=-0.000412 dist=0.028443 var=16.000000 first_ago=2.240792 last_ago=0.169985 selok=0
2015-01-29T10:46:48Z sourcestats.c:582:(SST_GetSelectionData) n=1 off=-0.000104 dist=0.006955 var=16.000000 first_ago=1.848336 last_ago=1.848336 selok=0
2015-01-29T10:46:48Z sourcestats.c:582:(SST_GetSelectionData) n=2 off=-0.000226 dist=0.003609 var=16.000000 first_ago=2.044231 last_ago=0.003384 selok=0
2015-01-29T10:46:48Z sources.c:695:(SRC_SelectSource) badstat=5 sel=0 badstat_reach=3 sel_reach=0 max_reach_ago=0.000000
2015-01-29T10:46:48Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.36.4:123]
2015-01-29T10:46:48Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.36.4:123 from [UNSPEC] fd 9
2015-01-29T10:46:48Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 192.87.36.4:123 to [UNSPEC] fd 9
2015-01-29T10:46:48Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-19 root_delay=0.000000 root_disp=0.000305 refid=47505300 []
2015-01-29T10:46:48Z ntp_core.c:1282:(receive_packet) reference=1422528404.225578 origin=1422528408.639559 receive=1422528408.642660 transmit=1422528408.642789
2015-01-29T10:46:48Z ntp_core.c:1284:(receive_packet) offset=0.000028 delay=0.006145 dispersion=0.000015 root_delay=0.006145 root_dispersion=0.000320
2015-01-29T10:46:48Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:48Z sources.c:356:(SRC_AccumulateSample) ip=[192.87.36.4] t=1422528408.642696 ofs=-0.000028 del=0.006145 disp=0.000320 str=1
2015-01-29T10:46:48Z sourcestats.c:582:(SST_GetSelectionData) n=2 off=-0.000412 dist=0.028866 var=16.000000 first_ago=2.452018 last_ago=0.381211 selok=0
2015-01-29T10:46:48Z sourcestats.c:582:(SST_GetSelectionData) n=2 off=-0.000028 dist=0.003399 var=16.000000 first_ago=2.059562 last_ago=0.003137 selok=0
2015-01-29T10:46:48Z sourcestats.c:582:(SST_GetSelectionData) n=2 off=-0.000226 dist=0.004031 var=16.000000 first_ago=2.255457 last_ago=0.214610 selok=0
2015-01-29T10:46:48Z sources.c:695:(SRC_SelectSource) badstat=5 sel=0 badstat_reach=3 sel_reach=0 max_reach_ago=0.000000
2015-01-29T10:46:48Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [145.145.170.84:123]
2015-01-29T10:46:48Z ntp_io.c:679:(send_packet) Sent 48 bytes to 145.145.170.84:123 from [UNSPEC] fd 7
2015-01-29T10:46:49Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.106.3:123]
2015-01-29T10:46:49Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.106..3:123 from [UNSPEC] fd 8
2015-01-29T10:46:50Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.106.2:123]
2015-01-29T10:46:50Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.106..2:123 from [UNSPEC] fd 9
2015-01-29T10:46:50Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 192.87.106.2:123 to [UNSPEC] fd 9
2015-01-29T10:46:50Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=2 poll=6 prec=-19 root_delay=0.001068 root_disp=0.026199 refid=c0576a03 []
2015-01-29T10:46:50Z ntp_core.c:1282:(receive_packet) reference=1422527685.662032 origin=1422528410.301807 receive=1422528410.303500 transmit=1422528410.303772
2015-01-29T10:46:50Z ntp_core.c:1284:(receive_packet) offset=0.000454 delay=0.002480 dispersion=0.000008 root_delay=0.003548 root_dispersion=0.026207
2015-01-29T10:46:50Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:50Z sources.c:356:(SRC_AccumulateSample) ip=[192.87.106.2] t=1422528410.303182 ofs=-0.000454 del=0.003548 disp=0.026207 str=2
2015-01-29T10:46:50Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=-0.000454 dist=0.027989 var=0.000000 first_ago=4.110743 last_ago=0.001376 selok=1
2015-01-29T10:46:50Z sourcestats.c:582:(SST_GetSelectionData) n=2 off=-0.000028 dist=0.006716 var=16.000000 first_ago=3.718287 last_ago=1.661862 selok=0
2015-01-29T10:46:50Z sourcestats.c:582:(SST_GetSelectionData) n=2 off=-0.000226 dist=0.007348 var=16.000000 first_ago=3.914182 last_ago=1.873335 selok=0
2015-01-29T10:46:50Z sources.c:695:(SRC_SelectSource) badstat=4 sel=1 badstat_reach=3 sel_reach=7 max_reach_ago=4.110743
2015-01-29T10:46:50Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [194.171.167.130:123]
2015-01-29T10:46:50Z ntp_io.c:679:(send_packet) Sent 48 bytes to 194.171.167.130:123 from [UNSPEC] fd 9
2015-01-29T10:46:50Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 194.171.167.130:123 to [UNSPEC] fd 9
2015-01-29T10:46:50Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-18 root_delay=0.000000 root_disp=0.000381 refid=50505300 []
2015-01-29T10:46:50Z ntp_core.c:1282:(receive_packet) reference=1422528400.826991 origin=1422528410.495440 receive=1422528410.498681 transmit=1422528410.498965
2015-01-29T10:46:50Z ntp_core.c:1284:(receive_packet) offset=0.000120 delay=0.006243 dispersion=0.000015 root_delay=0.006243 root_dispersion=0.000397
2015-01-29T10:46:50Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:50Z sources.c:356:(SRC_AccumulateSample) ip=[194.171.167..130] t=1422528410.498703 ofs=-0.000120 del=0.006243 disp=0.000397 str=1
2015-01-29T10:46:50Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=-0.000455 dist=0.029121 var=0.000000 first_ago=4.308151 last_ago=0.198784 selok=1
2015-01-29T10:46:50Z sourcestats.c:582:(SST_GetSelectionData) n=2 off=-0.000028 dist=0.007111 var=16.000000 first_ago=3.915695 last_ago=1.859270 selok=0
2015-01-29T10:46:50Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=-0.000120 dist=0.003570 var=0.000000 first_ago=4.111590 last_ago=0.003263 selok=1
2015-01-29T10:46:50Z sources.c:695:(SRC_SelectSource) badstat=3 sel=2 badstat_reach=3 sel_reach=7 max_reach_ago=4.308151
2015-01-29T10:46:50Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.36.4:123]
2015-01-29T10:46:50Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.36.4:123 from [UNSPEC] fd 9
2015-01-29T10:46:50Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 192.87.36.4:123 to [UNSPEC] fd 9
2015-01-29T10:46:50Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-19 root_delay=0.000000 root_disp=0.000336 refid=47505300 []
2015-01-29T10:46:50Z ntp_core.c:1282:(receive_packet) reference=1422528404.225578 origin=1422528410.696596 receive=1422528410.699605 transmit=1422528410.699734
2015-01-29T10:46:50Z ntp_core.c:1284:(receive_packet) offset=0.000014 delay=0.005987 dispersion=0.000014 root_delay=0.005987 root_dispersion=0.000350
2015-01-29T10:46:50Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:50Z sources.c:356:(SRC_AccumulateSample) ip=[192.87.36.4] t=1422528410.699655 ofs=-0.000014 del=0.005987 disp=0.000350 str=1
2015-01-29T10:46:50Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=-0.000456 dist=0.030274 var=0.000000 first_ago=4.508898 last_ago=0.399531 selok=1
2015-01-29T10:46:50Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=-0.000014 dist=0.003351 var=0.000000 first_ago=4.116442 last_ago=0.003058 selok=1
2015-01-29T10:46:50Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=-0.000115 dist=0.006795 var=0.000000 first_ago=4.312337 last_ago=0.204010 selok=1
2015-01-29T10:46:50Z sources.c:695:(SRC_SelectSource) badstat=2 sel=3 badstat_reach=0 sel_reach=7 max_reach_ago=4.508898
2015-01-29T10:46:50Z sources.c:944:(SRC_SelectSource) select score=31.873966 refid=c0576a02 match_refid=c0572404 status=0 dist=0.031374
2015-01-29T10:46:50Z sources.c:944:(SRC_SelectSource) select score=289.753201 refid=c0572404 match_refid=c0572404 status=0 dist=0.003451
2015-01-29T10:46:50Z sources.c:944:(SRC_SelectSource) select score=145.024567 refid=c2aba782 match_refid=c0572404 status=0 dist=0.006895
2015-01-29T10:46:50Z sourcestats.c:612:(SST_GetTrackingData) n=3 freq=0..000022 (22.321ppm) skew=0.002504 (2504.443ppm) avoff=-0.000011 offsd=0.000013 disp=0.000350
2015-01-29T10:46:50Z sourcestats.c:612:(SST_GetTrackingData) n=3 freq=-0.000004 (-4.486ppm) skew=0.005739 (5738.964ppm) avoff=-0.000451 offsd=0.000014 disp=0.026207
2015-01-29T10:46:50Z sourcestats.c:612:(SST_GetTrackingData) n=3 freq=0..000022 (22.321ppm) skew=0.002504 (2504.443ppm) avoff=-0.000011 offsd=0.000013 disp=0.000350
2015-01-29T10:46:50Z sources.c:564:(combine_sources) combining index=1 oweight=2.983994e+02 offset=-1.095398e-05 sd=1.340280e-05 fweight=3.992904e+02 freq=2.232132e-05 skew=2.504443e-03
2015-01-29T10:46:50Z sourcestats.c:612:(SST_GetTrackingData) n=3 freq=0..000023 (23.032ppm) skew=0.016066 (16065.770ppm) avoff=-0.000128 offsd=0.000037 disp=0.000397
2015-01-29T10:46:50Z sources.c:564:(combine_sources) combining index=3 oweight=1.471587e+02 offset=-1.228749e-04 sd=3.670327e-05 fweight=6.224414e+01 freq=2.303175e-05 skew=1.606577e-02
2015-01-29T10:46:50Z sources.c:585:(combine_sources) combined result offset=-4.791918e-05 sd=6.857415e-05 freq=2.241713e-05 skew=2.474557e-03
2015-01-29T10:46:50Z reference.c:726:(special_mode_sync) System's initial offset : 0.000048 seconds slow of true (slew)
2015-01-29T10:46:50Z sourcestats.c:650:(SST_SlewSamples) n=3 m=0 old_off_time=1422528410.303182 new=1422528410.303230 old_off=-0.000451 new_off=-0.000403 old_freq=-4.486 new_freq=-4.486
2015-01-29T10:46:50Z sourcestats.c:650:(SST_SlewSamples) n=3 m=0 old_off_time=1422528410.699655 new=1422528410.699703 old_off=-0.000011 new_off=0.000037 old_freq=22.321 new_freq=22.321
2015-01-29T10:46:50Z sourcestats.c:650:(SST_SlewSamples) n=3 m=0 old_off_time=1422528410.498703 new=1422528410.498751 old_off=-0.000128 new_off=-0.000080 old_freq=23.032 new_freq=23.032
2015-01-29T10:46:50Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [145.145.170.84:123]
2015-01-29T10:46:50Z ntp_io.c:679:(send_packet) Sent 48 bytes to 145.145.170.84:123 from [UNSPEC] fd 7
2015-01-29T10:46:51Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.106.3:123]
2015-01-29T10:46:51Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.106..3:123 from [UNSPEC] fd 8
2015-01-29T10:46:52Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [192.87.106.2:123]
2015-01-29T10:46:52Z ntp_io.c:679:(send_packet) Sent 48 bytes to 192.87.106..2:123 from [UNSPEC] fd 9
2015-01-29T10:46:52Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 192.87.106.2:123 to [UNSPEC] fd 9
2015-01-29T10:46:52Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=2 poll=6 prec=-19 root_delay=0.001068 root_disp=0.026230 refid=c0576a03 []
2015-01-29T10:46:52Z ntp_core.c:1282:(receive_packet) reference=1422527685.662032 origin=1422528412.332907 receive=1422528412.334626 transmit=1422528412.334748
2015-01-29T10:46:52Z ntp_core.c:1284:(receive_packet) offset=0.000401 delay=0.002636 dispersion=0.000008 root_delay=0.003704 root_dispersion=0.026237
2015-01-29T10:46:52Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:52Z sources.c:356:(SRC_AccumulateSample) ip=[192.87.106.2] t=1422528412.334286 ofs=-0.000401 del=0.003704 disp=0.026237 str=2
2015-01-29T10:46:52Z sourcestats.c:582:(SST_GetSelectionData) n=4 off=-0.000401 dist=0.028090 var=0.000000 first_ago=6.141802 last_ago=0.001379 selok=1
2015-01-29T10:46:52Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=0..000070 dist=0.007441 var=0.000000 first_ago=5.749346 last_ago=1.635962 selok=1
2015-01-29T10:46:52Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=-0.000030 dist=0.033029 var=0.000000 first_ago=5.945241 last_ago=1.836914 selok=1
2015-01-29T10:46:52Z sources.c:695:(SRC_SelectSource) badstat=2 sel=3 badstat_reach=0 sel_reach=f max_reach_ago=6.141802
2015-01-29T10:46:52Z sources.c:944:(SRC_SelectSource) select score=1.000000 refid=c0576a02 match_refid=c0576a02 status=0 dist=0.029190
2015-01-29T10:46:52Z sources.c:944:(SRC_SelectSource) select score=1.000000 refid=c0572404 match_refid=c0576a02 status=0 dist=0.007541
2015-01-29T10:46:52Z sources.c:944:(SRC_SelectSource) select score=1.000000 refid=c2aba782 match_refid=c0576a02 status=0 dist=0.033129
2015-01-29T10:46:52Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [194.171.167.130:123]
2015-01-29T10:46:52Z ntp_io.c:679:(send_packet) Sent 48 bytes to 194.171.167.130:123 from [UNSPEC] fd 9
2015-01-29T10:46:52Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 194.171.167.130:123 to [UNSPEC] fd 9
2015-01-29T10:46:52Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-18 root_delay=0.000000 root_disp=0.000412 refid=50505300 []
2015-01-29T10:46:52Z ntp_core.c:1282:(receive_packet) reference=1422528400.826991 origin=1422528412.531781 receive=1422528412.534386 transmit=1422528412.535658
2015-01-29T10:46:52Z ntp_core.c:1284:(receive_packet) offset=-0.000217 delay=0.005646 dispersion=0.000016 root_delay=0.005646 root_dispersion=0.000428
2015-01-29T10:46:52Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1111 kod_rate=0 valid=1 good=1
2015-01-29T10:46:52Z sources.c:356:(SRC_AccumulateSample) ip=[194.171.167..130] t=1422528412.535239 ofs=0.000217 del=0.005646 disp=0.000428 str=1
2015-01-29T10:46:52Z sourcestats.c:582:(SST_GetSelectionData) n=4 off=-0.000402 dist=0.028122 var=0.000000 first_ago=6.344834 last_ago=0.204411 selok=1
2015-01-29T10:46:52Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=0..000075 dist=0.007949 var=0.000000 first_ago=5.952378 last_ago=1.838994 selok=1
2015-01-29T10:46:52Z sourcestats.c:582:(SST_GetSelectionData) n=4 off=0..000217 dist=0.003253 var=0.000000 first_ago=6.148273 last_ago=0.003458 selok=1
2015-01-29T10:46:52Z sources.c:695:(SRC_SelectSource) badstat=2 sel=3 badstat_reach=0 sel_reach=f max_reach_ago=6.148273
2015-01-29T10:46:52Z sources.c:944:(SRC_SelectSource) select score=1.000000 refid=c0576a02 match_refid=c2aba782 status=0 dist=0.029222
2015-01-29T10:46:52Z sources.c:944:(SRC_SelectSource) select score=1.000000 refid=c0572404 match_refid=c2aba782 status=0 dist=0.008049
2015-01-29T10:46:52Z sources.c:944:(SRC_SelectSource) select score=2.370489 refid=c2aba782 match_refid=c2aba782 status=0 dist=0.003353
2015-01-29T10:46:52Z sourcestats.c:582:(SST_GetSelectionData) n=3 off=0..000079 dist=0.008387 var=0.000000 first_ago=6.127206 last_ago=2.013822 selok=1
2015-01-29T10:46:52Z sources.c:695:(SRC_SelectSource) badstat=2 sel=0 badstat_reach=0 sel_reach=0 max_reach_ago=0.000000
2015-01-29T10:46:52Z ntp_sources.c:476:(resolve_sources) resolving tt52.ripe.net
2015-01-29T10:46:52Z ntp_sources.c:376:(process_resolved_name) tt52.ripe.net resolved to 213.136.0.252
2015-01-29T10:46:53Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:46:53Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:46:53Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:46:53Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000397 refid=50505300 []
2015-01-29T10:46:53Z ntp_core.c:1282:(receive_packet) reference=1422528401.194382 origin=1422528413.082429 receive=1422528413.084979 transmit=1422528413.085012
2015-01-29T10:46:53Z ntp_core.c:1284:(receive_packet) offset=0.000414 delay=0.004272 dispersion=0.000011 root_delay=0.004272 root_dispersion=0.000407
2015-01-29T10:46:53Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0
2015-01-29T10:46:55Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:46:55Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:46:55Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:46:55Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000427 refid=50505300 []
2015-01-29T10:46:55Z ntp_core.c:1282:(receive_packet) reference=1422528401.194382 origin=1422528415.148491 receive=1422528415.150800 transmit=1422528415.150833
2015-01-29T10:46:55Z ntp_core.c:1284:(receive_packet) offset=0.000229 delay=0.004160 dispersion=0.000010 root_delay=0.004160 root_dispersion=0.000438
2015-01-29T10:46:55Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0
2015-01-29T10:46:57Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:46:57Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:46:57Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:46:57Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000458 refid=50505300 []
2015-01-29T10:46:57Z ntp_core.c:1282:(receive_packet) reference=1422528401.194382 origin=1422528417.163367 receive=1422528417.165648 transmit=1422528417.165679
2015-01-29T10:46:57Z ntp_core.c:1284:(receive_packet) offset=0.000241 delay=0.004079 dispersion=0.000010 root_delay=0.004079 root_dispersion=0.000468
2015-01-29T10:46:57Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0
2015-01-29T10:46:59Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:46:59Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:46:59Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:46:59Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000259 refid=50505300 []
2015-01-29T10:46:59Z ntp_core.c:1282:(receive_packet) reference=1422528417.194382 origin=1422528419.214391 receive=1422528419.216725 transmit=1422528419.216756
2015-01-29T10:46:59Z ntp_core.c:1284:(receive_packet) offset=-0.000584 delay=0.005835 dispersion=0.000014 root_delay=0.005835 root_dispersion=0.000273
2015-01-29T10:46:59Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0
2015-01-29T10:47:01Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:47:01Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:47:01Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:47:01Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000290 refid=50505300 []
2015-01-29T10:47:01Z ntp_core.c:1282:(receive_packet) reference=1422528417.194382 origin=1422528421.290280 receive=1422528421.292790 transmit=1422528421.292823
2015-01-29T10:47:01Z ntp_core.c:1284:(receive_packet) offset=0.000293 delay=0.004434 dispersion=0.000011 root_delay=0.004434 root_dispersion=0.000301
2015-01-29T10:47:01Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0
2015-01-29T10:47:03Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:47:03Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:47:03Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:47:03Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000320 refid=50505300 []
2015-01-29T10:47:03Z ntp_core.c:1282:(receive_packet) reference=1422528417.194382 origin=1422528423.338470 receive=1422528423.340869 transmit=1422528423.340900
2015-01-29T10:47:03Z ntp_core.c:1284:(receive_packet) offset=0.000236 delay=0.004325 dispersion=0.000011 root_delay=0.004325 root_dispersion=0.000331
2015-01-29T10:47:03Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0
2015-01-29T10:47:05Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:47:05Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:47:05Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:47:05Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000351 refid=50505300 []
2015-01-29T10:47:05Z ntp_core.c:1282:(receive_packet) reference=1422528417.194382 origin=1422528425.394233 receive=1422528425.396442 transmit=1422528425.396475
2015-01-29T10:47:05Z ntp_core.c:1284:(receive_packet) offset=0.000135 delay=0.004148 dispersion=0.000010 root_delay=0.004148 root_dispersion=0.000361
2015-01-29T10:47:05Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0
2015-01-29T10:47:07Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:47:07Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:47:07Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:47:07Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000381 refid=50505300 []
2015-01-29T10:47:07Z ntp_core.c:1282:(receive_packet) reference=1422528417.194382 origin=1422528427.485749 receive=1422528427.488247 transmit=1422528427.488279
2015-01-29T10:47:07Z ntp_core.c:1284:(receive_packet) offset=0.000271 delay=0.004454 dispersion=0.000011 root_delay=0.004454 root_dispersion=0.000392
2015-01-29T10:47:07Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0
2015-01-29T10:48:12Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:48:12Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:48:12Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:48:12Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000397 refid=50505300 []
2015-01-29T10:48:12Z ntp_core.c:1282:(receive_packet) reference=1422528481.194393 origin=1422528492.249540 receive=1422528492.251983 transmit=1422528492.252015
2015-01-29T10:48:12Z ntp_core.c:1284:(receive_packet) offset=0.000251 delay=0.004384 dispersion=0.000011 root_delay=0.004384 root_dispersion=0.000408
2015-01-29T10:48:12Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0
2015-01-29T10:49:17Z ntp_core.c:906:(transmit_timeout) Transmit timeout for [213.136.0.252:123]
2015-01-29T10:49:17Z ntp_io.c:679:(send_packet) Sent 48 bytes to 213.136.0.252:123 from [UNSPEC] fd 7
2015-01-29T10:49:17Z ntp_io.c:562:(read_from_socket) Received 48 bytes from 213.136.0.252:123 to [UNSPEC] fd 7
2015-01-29T10:49:17Z ntp_core.c:1277:(receive_packet) NTP packet lvm=44 stratum=1 poll=6 prec=-23 root_delay=0.000000 root_disp=0.000412 refid=50505300 []
2015-01-29T10:49:17Z ntp_core.c:1282:(receive_packet) reference=1422528545.194383 origin=1422528557.245619 receive=1422528557.248085 transmit=1422528557.248117
2015-01-29T10:49:17Z ntp_core.c:1284:(receive_packet) offset=0.000250 delay=0.004433 dispersion=0.000011 root_delay=0.004433 root_dispersion=0.000423
2015-01-29T10:49:17Z ntp_core.c:1287:(receive_packet) test123=111 test567=111 testABCD=1011 kod_rate=0 valid=1 good=0


-----Original Message-----
From: Miroslav Lichvar [mailto:mlichvar@xxxxxxxxxx] 
Sent: woensdag 28 januari 2015 12:44
To: chrony-dev@xxxxxxxxxxxxxxxxxxxx
Subject: Re: [chrony-dev] Chrony 2.0-pre1 fails on FreeBSD 10.1

On Wed, Jan 28, 2015 at 10:03:13AM +0000, Adri Koppes wrote:
> Chrony 1.31 was working without problems on FreeBSD 10.1.
> The new 2.0pre1 doesn't work at all, getting no samples from remote ntp servers.
> When I start 'chronyd -d -d', it seems there is never any data received, but also no errors are shown.
> 
> 2015-01-28T09:51:09Z main.c:433:(main) chronyd version 2.0-pre1 starting (+CMDMON +NTP +REFCLOCK -RTC -PRIVDROP -DEBUG +ASYNCDNS +IPV6 -SECHASH)

Can you please recompile chrony with --enable-debug and try again? It
should print more messages with -d -d.

> 2015-01-28T09:51:09Z sys_sunos.c:347:(setup_kernel) Cannot write to _dosynctodr
> 2015-01-28T09:51:09Z reference.c:193:(REF_Initialise) Frequency -9.849 +/- 0.069 ppm read from /var/db/chrony.drift
> 2015-01-28T09:51:14Z reference.c:726:(special_mode_sync) System's initial offset : 0.001379 seconds slow of true (slew)

Hm, the message above says there was some NTP response for initstepslew.

> Using chronyc to view the statusm, chronyd says the remote server is reachable, but again last RX is 10y.
> 
> chronyc> sources
> 210 Number of sources = 1
> MS Name/IP address         Stratum Poll Reach LastRx Last sample
> ===============================================================================
> ^? ntp4.bit.nl                   0   6   377   10y     +0ns[   +0ns] +/-    0ns

That's interesting :).

-- 
Miroslav Lichvar

-- 
To unsubscribe email chrony-dev-request@xxxxxxxxxxxxxxxxxxxx with "unsubscribe" in the subject.
For help email chrony-dev-request@xxxxxxxxxxxxxxxxxxxx with "help" in the subject.
Trouble?  Email listmaster@xxxxxxxxxxxxxxxxxxxx.


--
To unsubscribe email chrony-dev-request@xxxxxxxxxxxxxxxxxxxx with "unsubscribe" in the subject.
For help email chrony-dev-request@xxxxxxxxxxxxxxxxxxxx with "help" in the subject.
Trouble?  Email listmaster@xxxxxxxxxxxxxxxxxxxx.


Mail converted by MHonArc 2.6.19+ http://listengine.tuxfamily.org/