[ntp:questions] Assistance with PPS on Windows

Ken Link klink at numberzero.org
Wed May 4 18:06:29 UTC 2011


Here is the debug output from running "ntpd.exe -M -g -c "C:\Program
Files\NTP\etc\ntp.conf" -n -D3"

ntpq 4.2.6p3 at 1.2290-o Apr 29 9:05:35.49 (UTC-05:00) 2011  (4)
 4 May 12:54:31 ntpd.exe[4808]: Raised to realtime priority class
 4 May 12:54:31 ntpd.exe[4808]: MM timer resolution: 1..1000000 msec,
set to 1 msec
 4 May 12:54:31 ntpd.exe[4808]: Performance counter frequency 3.580 MHz
 4 May 12:54:31 ntpd.exe[4808]: Clock interrupt period 15.625 msec
 4 May 12:54:31 ntpd.exe[4808]: Windows clock precision 15.625 msec,
min. slew 6.400 ppm/s
 4 May 12:54:31 ntpd.exe[4808]: HZ 64.000 using 43 msec timer 23.256 Hz 64 deep
 4 May 12:54:34 ntpd.exe[4808]: set_process_priority: Leave priority
alone: priority_done is <2>
 4 May 12:54:34 ntpd.exe[4808]: proto: precision = 2.200 usec
loop_config: item 1 freq 0.000000
Finished Parsing!!
create_sockets(123)
Allocation 32 memory for io_completion_port_add_socket, ptr 3dfcb0
 4 May 12:54:34 ntpd.exe[4808]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
created interface #0: fd=1856, bfd=-1, name=v4wildcard, flags=0x89,
ifindex=0, sin=0.0.0.0, bcast=0.0.0.0, mask=255.255.255.255, Disabled:
update_interfaces(123)
create_interface(172.16.77.45#123)
Allocation 32 memory for io_completion_port_add_socket, ptr 3dffd8
 4 May 12:54:34 ntpd.exe[4808]: Listen normally on 1 Local Area
Connection 172.16.77.45 UDP 123
restrict: op 1 addr 172.16.77.45 mask 255.255.255.255 mflags 00003000
flags 00000001
created interface #1: fd=1608, bfd=-1, name=Local Area Connection,
flags=0x19, ifindex=0, sin=172.16.77.45, bcast=172.16.79.255,
mask=255.255.248.0, Enabled:
updating interface #1: fd=1608, bfd=-1, name=Local Area Connection,
flags=0x19, ifindex=0, sin=172.16.77.45, bcast=172.16.79.255,
mask=255.255.248.0, Enabled: new - created
create_interface(127.0.0.1#123)
Allocation 32 memory for io_completion_port_add_socket, ptr ea4620
 4 May 12:54:34 ntpd.exe[4808]: Listen normally on 2 MS TCP Loopback
interface 127.0.0.1 UDP 123
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00003000
flags 00000001
created interface #2: fd=1596, bfd=-1, name=MS TCP Loopback interface,
flags=0x15, ifindex=0, sin=127.0.0.1, mask=255.255.255.255, Enabled:
updating interface #2: fd=1596, bfd=-1, name=MS TCP Loopback
interface, flags=0x15, ifindex=0, sin=127.0.0.1, mask=255.255.255.255,
Enabled: new - created
 4 May 12:54:34 ntpd.exe[4808]: peers refreshed
time_pps_create(4) got winhandle 00000634
getenv(PPSAPI_DLLS) gives
c:\serialpps\serialpps-ppsapi-provider\x86\serialpps-ppsapi-provider.dll
loaded PPSAPI provider serialpps.sys, serial.sys with CD timestamping
added caps 0x3011 provider 00EA5F30
serialpps prov_time_pps_create(00000634) returned 0
 4 May 12:54:34 ntpd.exe[4808]: ntp_timestamp_from_counter
interpolated time 413279.091756s from current
create_sockets: Total interfaces = 3
io_open_sockets: maxactivefd 0
auth_setkey: key 65535 type 4 len 4 8bf9a728
proto_config: code 11 value 1 dvalue 0.000000
newpeer: cast flags: 0x1 for address: 127.127.22.1
newpeer: using fd 1596 and our addr 127.0.0.1
key_expire: at 0 associd 29554
peer_clear: at 0 next 1 associd 29554 refid INIT
common_serial_open given /dev/pps1
common_serial_open skipped to ending digits leaving 1
windows device \\.\COM1
event at 0 PPS(1) 8011 81 mobilize assoc 29554
newpeer: 127.0.0.1->127.127.22.1 mode 3 vers 4 poll 4 4 flags 0x9 0x1
ttl 0 key 00000000
newpeer: cast flags: 0x1 for address: 172.16.77.44
newpeer: using fd 1608 and our addr 172.16.77.45
key_expire: at 0 associd 29555
peer_clear: at 0 next 2 associd 29555 refid INIT
event at 0 172.16.77.44 8011 81 mobilize assoc 29555
newpeer: 172.16.77.45->172.16.77.44 mode 1 vers 4 poll 6 10 flags
0x121 0x1 ttl 0 key 00000000
event at 0 0.0.0.0 c016 06 restart
loop_config: item 2 freq 0.000293
event at 0 0.0.0.0 c012 02 freq_set ntpd 293.069 PPM
local_clock: mu 0 state 2 poll 3 count 0
SetSystemTimeAdjustment(+46)
ntp_timestamp_from_counter interpolated time 413279.091756s from current
interpol time 1cc06c2164f3cb8 from  0
Freeing memory for free_io_completion_port_mem, ptr ea4620
Freeing memory for free_io_completion_port_mem, ptr 3dffd8
Freeing memory for free_io_completion_port_mem, ptr 3dfcb0
MM timer resolution reset
Overlapped IO Thread Exiting
 4 May 12:54:34 ntpd.exe[4808]: ntservice: The Network Time Protocol
Service is stopping.

-------------

It appears to work correctly until this line, and then it shuts itself
down: "ntp_timestamp_from_counter interpolated time 413279.091756s
from current"

Running ntpdate shows the offset is within +/- 0.05 sec most of the
time, including during that debug output. Remember the Meinberg card
is locked to the IRIG B signal coming off the Arbiter clock...so I
would expect that to be synced, thus keeping the PPS output synced as
well.

Ken

On Wed, May 4, 2011 at 8:34 AM, Dave Hart <hart at ntp.org> wrote:
> Hi Ken,
>
> The ATOM driver is not considered until the system clock has been
> steered within 0.4s of the PPS signal.  To troubleshoot, you could
> install debug ntpd.exe and invoke it from a command prompt, adding -n
> -D3 or similar to the command-line options to run interactively and
> enable debugging output.
>
> Good luck,
> Dave Hart
>



More information about the questions mailing list