PTP client operational, yet system time is wrong #20
Description
I seem to have a working PTP setup syncing with a SecureSync 2400 on Windows server 2022 (20348.2113), and i see time adjustment messages in the event log, yet time on the computer is wrong by about 37 seconds. What gives? I have pasted the output/contents of various commands and logs below. The only thing i see that is perhaps a problem is that PTP_UTC_REASONABLE is false, but then it seems that frequency adjustments are being made anyway. Do i need to get this set to true for things to start working, or could it be something else?
And actually, i would expect the clock offset to just be fixed in a single shot instead of using frequency adjustment, since i set the MaxAllowedPhaseOffset to 1 (on purpose, i want any larger offsets that may have occurred when the computer has been off for a while to be corrected immediately at boot), and the offset is about 37 seconds.
PTP announcement (wireshark)
Frame 1404: 106 bytes on wire (848 bits), 106 bytes captured (848 bits) on interface \Device\NPF_{EA16C3AA-09A7-4A63-A260-696645DE1AF7}, id 0
Ethernet II, Src: SafranTruste_0e:02:17 (00:0c:ec:0e:xx:xx), Dst: IPv4mcast_01:81 (01:00:5e:00:01:81)
Internet Protocol Version 4, Src: 10.0.1.251, Dst: 224.0.1.129
User Datagram Protocol, Src Port: 320, Dst Port: 320
Precision Time Protocol (IEEE1588)
0000 .... = majorSdoId: Unknown (0x0)
.... 1011 = messageType: Announce Message (0xb)
0000 .... = minorVersionPTP: 0
.... 0010 = versionPTP: 2
messageLength: 64
domainNumber: 0
minorSdoId: 0
flags: 0x0008
0... .... .... .... = PTP_SECURITY: False
.0.. .... .... .... = PTP profile Specific 2: False
..0. .... .... .... = PTP profile Specific 1: False
.... .0.. .... .... = PTP_UNICAST: False
.... ..0. .... .... = PTP_TWO_STEP: False
.... ...0 .... .... = PTP_ALTERNATE_MASTER: False
.... .... .0.. .... = SYNCHRONIZATION_UNCERTAIN: False
.... .... ..0. .... = FREQUENCY_TRACEABLE: False
.... .... ...0 .... = TIME_TRACEABLE: False
.... .... .... 1... = PTP_TIMESCALE: True
.... .... .... .0.. = PTP_UTC_REASONABLE: False
.... .... .... ..0. = PTP_LI_59: False
.... .... .... ...0 = PTP_LI_61: False
correctionField: 0.000000 nanoseconds
messageTypeSpecific: 0
ClockIdentity: 0x000cecfffexxxxxx
SourcePortID: 1
sequenceId: 59082
controlField: Other Message (5)
logMessagePeriod: 1 (2.000000 s)
originTimestamp (seconds): 0
originTimestamp (nanoseconds): 0
originCurrentUTCOffset: 37
priority1: 0
grandmasterClockClass: 248
grandmasterClockAccuracy: Accuracy Unknown (0xfe)
grandmasterClockVariance: 65535
priority2: 0
grandmasterClockIdentity: 0x000cecfffexxxxxx
localStepsRemoved: 0
TimeSource: INTERNAL_OSCILLATOR (0xa0)
[Community ID: 1:5HscnTbdWc0XmMZIq8DQywsKyKs=]
Spirent Test Center Signature
Raw Data: 0000000000250000f8feffff00000cecfffe0e02
IV: 0x00
StreamID: 0
ChassisSlotPort: 0
0... .... = StreamType: Soft
Stream Index: 0
Sequence Number (SM): 40681946545919
Timestamp: 644.081260556 seconds
.... ..0. = Pseudo-Random Binary Sequence: False
.... ...0 = TSLR: StartOfFrame
Unknown: fffe0e02
w32tm /query /configuration /verbose
[Configuration]
EventLogFlags: 2 (Local)
AnnounceFlags: 10 (Local)
TimeJumpAuditOffset: 28800 (Local)
MinPollInterval: 6 (Local)
MaxPollInterval: 6 (Local)
MaxNegPhaseCorrection: 54000 (Local)
MaxPosPhaseCorrection: 54000 (Local)
MaxAllowedPhaseOffset: 1 (Local)
FrequencyCorrectRate: 2 (Local)
PollAdjustFactor: 5 (Local)
LargePhaseOffset: 50000000 (Local)
SpikeWatchPeriod: 900 (Local)
LocalClockDispersion: 10 (Local)
HoldPeriod: 5 (Local)
PhaseCorrectRate: 1 (Local)
UpdateInterval: 100 (Local)
FileLogName: C:\Windows\Temp\w32time.log (Local)
FileLogEntries: 0-116 (Local)
FileLogSize: 268435456 (Local)
FileLogFlags: 0 (Undefined or NotUsed)
[TimeProviders]
PtpClient (Local)
DllName: C:\Windows\system32\ptpprov.dll (Local)
Enabled: 1 (Local)
InputProvider: 1 (Local)
NtpClient (Local)
DllName: C:\Windows\system32\w32time.dll (Local)
Enabled: 0 (Local)
InputProvider: 1 (Local)
NtpServer (Local)
DllName: C:\Windows\system32\w32time.dll (Local)
Enabled: 0 (Local)
InputProvider: 0 (Local)
VMICTimeProvider (Local)
DllName: C:\Windows\System32\vmictimeprovider.dll (Local)
Enabled: 0 (Local)
InputProvider: 1 (Local)
w32tm /query /status /verbose
Leap Indicator: 0(no warning)
Stratum: 3 (secondary reference - syncd by (S)NTP)
Precision: -23 (119.209ns per tick)
Root Delay: 0.0001952s
Root Dispersion: 0.0100020s
ReferenceId: 0x4D505450 (source IP: 77.80.84.80)
Last Successful Sync Time: 2023-12-18 11:21:39
Source: 10.0.1.251
Poll Interval: 6 (64s)
Phase Offset: 0.0000579s
ClockRate: 0.0156251s
State Machine: 2 (Sync)
Time Source Flags: 0 (None)
Server Role: 0 (None)
Last Sync Error: 0 (The command completed successfully.)
Time since Last Good Sync Time: 29.6717837s
w32tm /stripchart /computer:10.0.1.251
Tracking 10.0.1.251 [10.0.1.251:123].
The current time is 2023-12-18 11:36:30.
11:36:30, d:+00.0038991s o:-36.9978659s [@ | ]
11:36:32, d:+00.0002918s o:-36.9995415s [@ | ]
11:36:34, d:+00.0003251s o:-36.9995590s [@ | ]
11:36:36, d:+00.0003021s o:-36.9995718s [@ | ]
11:36:38, d:+00.0152755s o:-37.0070442s [@ | ]
11:36:40, d:+00.0004959s o:-36.9996000s [@ | ]
11:36:42, d:+00.0003251s o:-36.9995826s [@ | ]
w32time.log_ptpprov
154483 10:02:27.6534396s - ---------- Log File Opened -----------------
154483 10:02:27.6536102s - ReadConfig: 'DelayPollInterval'= 16000
154483 10:02:27.6536420s - ReadConfig: 'AnnounceInterval'= 4000
154483 10:02:27.6536643s - RegGetValue error. value:AllowAnyMaster Error:0x80070002
154483 10:02:27.6536860s - ReadConfig: 'EnableMulticastRx'= 1
154483 10:02:27.6538302s - RegGetValue error. value:EnableMulticastTx Error:0x80070002
154483 10:02:27.6538491s - RegGetValue error. value:UseE2ECorrection Error:0x80070002
154483 10:02:27.6538674s - ReadConfig: 'PtpMasters'= 10.0.1.251
154483 10:02:27.6538805s - RegGetValue error. value:DomainNumber Error:0x80070002
154483 10:02:27.6593239s - pwszMastersList:10.0.1.251
delayPollIntervalMsec:16000
announceIntervalMsec:4000announceReceiptTimeoutMsec:12000
bSMO:1bUseTimestamps:0
bAllowAnyMaster:0
bMulticast:Rx
bUseE2ECorrection:0
154483 10:02:27.6593851s - bAAD:0
bERM:0
154483 10:02:27.6683452s - Adapter Count:5
154483 10:02:27.6683642s - NIC HW Timestamping enabled on adapter LUID:0x0006008004000000
154483 10:02:27.6683796s - NIC HW Timestamping enabled on adapter LUID:0x0006008003000000
154483 10:02:27.6720736s - PtpProvider: Created 2 sockets (0 listen-only): [::]:319<0x0>, 0.0.0.0:319<0x0>
154483 10:02:27.6722343s - PtpProvider: Created 2 sockets (0 listen-only): [::]:320<0x0>, 0.0.0.0:320<0x0>
154483 10:02:27.6723195s - StartListeningThread completed for event port socket(s)
154483 10:02:27.6723370s - StartListeningThread completed for general port socket(s)
154483 10:02:28.3223043s - Rx timestamp not returned and may be unsupported on the current network interface.
154483 10:02:28.6418306s - ListeningThread: StopEvent
154483 10:02:28.6443582s - ReadConfig: 'DelayPollInterval'= 16000
154483 10:02:28.6443763s - ReadConfig: 'AnnounceInterval'= 4000
154483 10:02:28.6443858s - RegGetValue error. value:AllowAnyMaster Error:0x80070002
154483 10:02:28.6443946s - ReadConfig: 'EnableMulticastRx'= 1
154483 10:02:28.6444037s - RegGetValue error. value:EnableMulticastTx Error:0x80070002
154483 10:02:28.6444559s - RegGetValue error. value:UseE2ECorrection Error:0x80070002
154483 10:02:28.6444692s - ReadConfig: 'PtpMasters'= 10.0.1.251
154483 10:02:28.6444784s - RegGetValue error. value:DomainNumber Error:0x80070002
154483 10:02:28.6464769s - pwszMastersList:10.0.1.251
delayPollIntervalMsec:16000
announceIntervalMsec:4000announceReceiptTimeoutMsec:12000
bSMO:1bUseTimestamps:0
bAllowAnyMaster:0
bMulticast:Rx
bUseE2ECorrection:0
154483 10:02:28.6465199s - bAAD:0
bERM:0
154483 10:02:28.6556120s - Adapter Count:5
154483 10:02:28.6556259s - NIC HW Timestamping enabled on adapter LUID:0x0006008004000000
154483 10:02:28.6556370s - NIC HW Timestamping enabled on adapter LUID:0x0006008003000000
154483 10:02:28.6580285s - PtpProvider: Created 2 sockets (0 listen-only): [::]:319<0x0>, 0.0.0.0:319<0x0>
154483 10:02:28.6581266s - PtpProvider: Created 2 sockets (0 listen-only): [::]:320<0x0>, 0.0.0.0:320<0x0>
154483 10:02:28.6581816s - StartListeningThread completed for event port socket(s)
154483 10:02:28.6581932s - StartListeningThread completed for general port socket(s)
154483 10:02:29.3326814s - if:5, RxSTMP:6079177272, QPC:64530938216
154483 10:02:29.3327004s - HA Pkt Rx: delay:0 DestTimeStamp:133473673493326594
154483 10:02:29.5503608s - Added new master ClockId:0x17020EFEFFEC0C00 PortNum:0x100 SequenceId:58914
154483 10:02:30.3224855s - if:5, RxSTMP:7079207872, QPC:64530938216
154483 10:02:30.3225017s - HA Pkt Rx: delay:0 DestTimeStamp:133473673503224710
154483 10:02:31.3226169s - if:5, RxSTMP:8079252880, QPC:64530938216
154483 10:02:31.3226379s - HA Pkt Rx: delay:0 DestTimeStamp:133473673513225994
154483 10:02:32.3228776s - if:5, RxSTMP:9079298544, QPC:64529887880
154483 10:02:32.3229342s - HA Pkt Rx: delay:0 DestTimeStamp:133473673523228325
154483 10:02:33.3228910s - if:5, RxSTMP:10079342416, QPC:64530938216
154483 10:02:33.3229153s - HA Pkt Rx: delay:0 DestTimeStamp:133473673533228703
154483 10:02:34.3229880s - if:5, RxSTMP:11079392024, QPC:64529887880
154483 10:02:34.3230977s - HA Pkt Rx: delay:0 DestTimeStamp:133473673543229574
154483 10:02:35.3231782s - if:5, RxSTMP:12079491744, QPC:64530938216
154483 10:02:35.3232311s - HA Pkt Rx: delay:0 DestTimeStamp:133473673553231390
154483 10:02:36.3232448s - if:5, RxSTMP:13079541472, QPC:64529887880
154483 10:02:36.3232990s - HA Pkt Rx: delay:0 DestTimeStamp:133473673563232057
154483 10:02:37.3233489s - if:5, RxSTMP:14079619072, QPC:64529887880
154483 10:02:37.3234009s - HA Pkt Rx: delay:0 DestTimeStamp:133473673573233133
154483 10:02:38.3234345s - if:5, RxSTMP:15079668928, QPC:64530938216
154483 10:02:38.3234805s - HA Pkt Rx: delay:0 DestTimeStamp:133473673583233993
154483 10:02:39.3234997s - if:5, RxSTMP:16079700032, QPC:64529887880
154483 10:02:39.3235347s - HA Pkt Rx: delay:0 DestTimeStamp:133473673593234726
154483 10:02:40.3236015s - if:5, RxSTMP:17079850456, QPC:64530938216
154483 10:02:40.3236201s - HA Pkt Rx: delay:0 DestTimeStamp:133473673603235848
154483 10:02:41.3235524s - if:5, RxSTMP:18079834320, QPC:64530938216
154483 10:02:41.3235706s - HA Pkt Rx: delay:0 DestTimeStamp:133473673613235368
154483 10:02:42.3238010s - if:5, RxSTMP:19079883032, QPC:64530938216
154483 10:02:42.3238515s - HA Pkt Rx: delay:0 DestTimeStamp:133473673623237642
154483 10:02:43.3238672s - if:5, RxSTMP:20079927856, QPC:64529887880
154483 10:02:43.3239085s - HA Pkt Rx: delay:0 DestTimeStamp:133473673633238366
154483 10:02:44.3239385s - if:5, RxSTMP:21079975880, QPC:64530938216
154483 10:02:44.3239722s - HA Pkt Rx: delay:0 DestTimeStamp:133473673643239143
154483 10:02:45.3240796s - if:5, RxSTMP:22080030640, QPC:64529887880
154483 10:02:45.3241365s - HA Pkt Rx: delay:0 DestTimeStamp:133473673653240424
154483 10:02:46.3241211s - if:5, RxSTMP:23080066976, QPC:64530938216
154483 10:02:46.3241689s - HA Pkt Rx: delay:0 DestTimeStamp:133473673663240874
154483 10:02:47.3242312s - if:5, RxSTMP:24080113960, QPC:64529887880
154483 10:02:47.3242829s - HA Pkt Rx: delay:0 DestTimeStamp:133473673673241987
154483 10:02:48.3242878s - if:5, RxSTMP:25080158920, QPC:64530938216
154483 10:02:48.3243419s - HA Pkt Rx: delay:0 DestTimeStamp:133473673683242568
154483 10:02:49.3244005s - if:5, RxSTMP:26080207688, QPC:64529887880
154483 10:02:49.3244509s - HA Pkt Rx: delay:0 DestTimeStamp:133473673693243677
154483 10:02:50.3244615s - if:5, RxSTMP:27080254432, QPC:64530938216
154483 10:02:50.3245095s - HA Pkt Rx: delay:0 DestTimeStamp:133473673703244316
154483 10:02:51.3245661s - if:5, RxSTMP:28080295168, QPC:64529887880
154483 10:02:51.3246149s - HA Pkt Rx: delay:0 DestTimeStamp:133473673713245350
154483 10:02:52.3246305s - if:5, RxSTMP:29080344584, QPC:64530938216
154483 10:02:52.3246803s - HA Pkt Rx: delay:0 DestTimeStamp:133473673723245988
154483 10:02:52.9392730s - Polling peer 10.0.1.251 for delay
154483 10:02:52.9395308s - Tx Delay_Req packet ClientTimestamp:133473673729393246 sequenceId:1 hr:0x00000000
154483 10:02:52.9396025s - Get timestamp error:0x80072733 dwBytesReturned:0
154483 10:02:52.9403371s - Rx Delay_Resp packet llCorrection:0 servertimestamp:133473673726362704 SequenceId:1
154483 10:02:52.9549019s - if:5(0?), TxSTMP:29695706704, QPC:64528841080
154483 10:02:52.9549523s - HA Pkt Tx: delay:0 DestTimeStamp:2092800775616
154483 10:02:53.3245966s - if:5, RxSTMP:30080394824, QPC:64529887880
154483 10:02:53.3246207s - HA Pkt Rx: delay:0 DestTimeStamp:133473673733245822
154483 10:02:54.3248307s - if:5, RxSTMP:31080438552, QPC:64529887880
154483 10:02:54.3248818s - HA Pkt Rx: delay:0 DestTimeStamp:133473673743247973
154483 10:02:55.3248926s - if:5, RxSTMP:32080487704, QPC:64530938216
154483 10:02:55.3249409s - HA Pkt Rx: delay:0 DestTimeStamp:133473673753248611
154483 10:02:56.3249869s - if:5, RxSTMP:33080529832, QPC:64529887880
154483 10:02:56.3250368s - HA Pkt Rx: delay:0 DestTimeStamp:133473673763249554
154483 10:02:57.3250648s - if:5, RxSTMP:34080577200, QPC:64530938216
154483 10:02:57.3251141s - HA Pkt Rx: delay:0 DestTimeStamp:133473673773250308
154483 10:02:58.3251679s - if:5, RxSTMP:35080622248, QPC:64529887880
154483 10:02:58.3253322s - HA Pkt Rx: delay:0 DestTimeStamp:133473673783251311
154483 10:02:59.3252391s - if:5, RxSTMP:36080668664, QPC:64530938216
154483 10:02:59.3252897s - HA Pkt Rx: delay:0 DestTimeStamp:133473673793252049
154483 10:03:00.3253572s - if:5, RxSTMP:37080719584, QPC:64529887880
154483 10:03:00.3254094s - HA Pkt Rx: delay:0 DestTimeStamp:133473673803253204
154483 10:03:01.3138684s - if:5, RxSTMP:38080764584, QPC:64530938216
154483 10:03:01.3139004s - HA Pkt Rx: delay:0 DestTimeStamp:133473673813138457
154483 10:03:02.2961141s - if:5, RxSTMP:39080878832, QPC:64529887880
154483 10:03:02.2961523s - HA Pkt Rx: delay:0 DestTimeStamp:133473673822960709
154483 10:03:03.2793205s - if:5, RxSTMP:40080894936, QPC:64530938216
154483 10:03:03.2793672s - HA Pkt Rx: delay:0 DestTimeStamp:133473673832792891
154483 10:03:04.2636080s - if:5, RxSTMP:41080943560, QPC:64529887880
154483 10:03:04.2636427s - HA Pkt Rx: delay:0 DestTimeStamp:133473673842635857
154483 10:03:05.2488832s - if:5, RxSTMP:42081089688, QPC:64530938216
154483 10:03:05.2489134s - HA Pkt Rx: delay:0 DestTimeStamp:133473673852488628
154483 10:03:06.2350034s - if:5, RxSTMP:43081082504, QPC:64530938216
154483 10:03:06.2350498s - HA Pkt Rx: delay:0 DestTimeStamp:133473673862349730
154483 10:03:07.2220168s - if:5, RxSTMP:44081133856, QPC:64529887880
154483 10:03:07.2220695s - HA Pkt Rx: delay:0 DestTimeStamp:133473673872219778
154483 10:03:08.2097979s - if:5, RxSTMP:45081178640, QPC:64530938216
154483 10:03:08.2098559s - HA Pkt Rx: delay:0 DestTimeStamp:133473673882097582
154483 10:03:09.1982821s - if:5, RxSTMP:46081222656, QPC:64529887880
154483 10:03:09.1983318s - HA Pkt Rx: delay:0 DestTimeStamp:133473673891982485
154483 10:03:10.1875075s - if:5, RxSTMP:47081270240, QPC:64530938216
154483 10:03:10.1875609s - HA Pkt Rx: delay:0 DestTimeStamp:133473673901874757
154483 10:03:11.1774018s - if:5, RxSTMP:48081315336, QPC:64529887880
154483 10:03:11.1774339s - HA Pkt Rx: delay:0 DestTimeStamp:133473673911773806
154483 10:03:12.1679061s - if:5, RxSTMP:49081362536, QPC:64530938216
154483 10:03:12.1679372s - HA Pkt Rx: delay:0 DestTimeStamp:133473673921678877
154483 10:03:13.1590159s - if:5, RxSTMP:50081407696, QPC:64529887880
154483 10:03:13.1590635s - HA Pkt Rx: delay:0 DestTimeStamp:133473673931589850
154483 10:03:14.1506740s - if:5, RxSTMP:51081459216, QPC:64530938216
154483 10:03:14.1507236s - HA Pkt Rx: delay:0 DestTimeStamp:133473673941506412
154483 10:03:14.6895072s - ListeningThread: StopEvent
154483 10:03:14.6925235s - ReadConfig: 'DelayPollInterval'= 16000
154483 10:03:14.6925503s - ReadConfig: 'AnnounceInterval'= 4000
154483 10:03:14.6925615s - RegGetValue error. value:AllowAnyMaster Error:0x80070002
154483 10:03:14.6925714s - ReadConfig: 'EnableMulticastRx'= 1
154483 10:03:14.6925815s - RegGetValue error. value:EnableMulticastTx Error:0x80070002
154483 10:03:14.6925914s - RegGetValue error. value:UseE2ECorrection Error:0x80070002
154483 10:03:14.6926036s - ReadConfig: 'PtpMasters'= 10.0.1.251
154483 10:03:14.6926136s - RegGetValue error. value:DomainNumber Error:0x80070002
154483 10:03:14.6948696s - pwszMastersList:10.0.1.251
delayPollIntervalMsec:16000
announceIntervalMsec:4000announceReceiptTimeoutMsec:12000
bSMO:1bUseTimestamps:0
bAllowAnyMaster:0
bMulticast:Rx
bUseE2ECorrection:0
154483 10:03:14.6949298s - bAAD:0
bERM:0
154483 10:03:14.6974189s - Adapter Count:5
154483 10:03:14.6974422s - NIC HW Timestamping enabled on adapter LUID:0x0006008004000000
154483 10:03:14.6974568s - NIC HW Timestamping enabled on adapter LUID:0x0006008003000000
154483 10:03:14.7073531s - PtpProvider: Created 2 sockets (0 listen-only): [::]:319<0x0>, 0.0.0.0:319<0x0>
154483 10:03:14.7075307s - PtpProvider: Created 2 sockets (0 listen-only): [::]:320<0x0>, 0.0.0.0:320<0x0>
154483 10:03:14.7076055s - StartListeningThread completed for event port socket(s)
154483 10:03:14.7076238s - StartListeningThread completed for general port socket(s)
154483 10:03:15.1428906s - if:12, RxSTMP:52511089571, QPC:64529887880
154483 10:03:15.1429429s - HA Pkt Rx: delay:0 DestTimeStamp:133473673951428541
154483 10:03:15.1429917s - if:5, RxSTMP:52081499456, QPC:64529887784
154483 10:03:15.1430132s - HA Pkt Rx: delay:0 DestTimeStamp:133473673951429749
154483 10:03:15.1430791s - if:12, RxSTMP:52510962989, QPC:64529887880
154483 10:03:15.1430994s - HA Pkt Rx: delay:0 DestTimeStamp:133473673951430641
154483 10:03:15.1431479s - Rx timestamp not returned and may be unsupported on the current network interface.
154483 10:03:15.3668671s - Added new master ClockId:0x17020EFEFFEC0C00 PortNum:0x100 SequenceId:58937
154483 10:03:15.3669933s - if:12, RxSTMP:52736863382, QPC:64530938216
154483 10:03:15.3670371s - HA Pkt Rx: delay:0 DestTimeStamp:133473673953669609
154483 10:03:15.3670623s - Added new master ClockId:0x17020EFEFFEC0C00 PortNum:0x100 SequenceId:58937
154483 10:03:15.3671086s - Added new master ClockId:0x17020EFEFFEC0C00 PortNum:0x100 SequenceId:58937
154483 10:03:16.1354843s - if:5, RxSTMP:53081549320, QPC:64528840040
154483 10:03:16.1355409s - HA Pkt Rx: delay:0 DestTimeStamp:133473673961354475
154483 10:03:16.1356254s - if:12, RxSTMP:53511516207, QPC:64529887880
154483 10:03:16.1356729s - HA Pkt Rx: delay:0 DestTimeStamp:133473673961355934
154483 10:03:16.1357519s - if:12, RxSTMP:53511647783, QPC:64530938216
154483 10:03:16.1357991s - HA Pkt Rx: delay:0 DestTimeStamp:133473673961357184
154483 10:03:16.1358462s - Rx timestamp not returned and may be unsupported on the current network interface.
154483 10:03:17.1285415s - if:5, RxSTMP:54081593968, QPC:64528840040
154483 10:03:17.1285743s - HA Pkt Rx: delay:0 DestTimeStamp:133473673971285201
w32time.log
154483 10:02:27.6447315s - ---------- Log File Opened -----------------
154483 10:02:27.6454506s - ReadConfig: Found provider 'NtpClient':
154483 10:02:27.6455361s - ReadConfig: 'InputProvider'=0x00000001
154483 10:02:27.6455651s - ReadConfig: 'MetaDataProvider'=0x00000000
154483 10:02:27.6455884s - ReadConfig: 'DllName'='C:\Windows\system32\w32time.dll'
154483 10:02:27.6456979s - ReadConfig: 'DllName'='C:\Windows\system32\w32time.dll'
154483 10:02:27.6458117s - PowerNotificationCallback: Data:0 SuspendState:0
154483 10:02:27.6458392s - PowerNotificationCallback: Ignoring resume notification since we never entered suspend state.
154483 10:02:27.6457145s - ReadConfig: 'DllName'='C:\Windows\system32\w32time.dll'
154483 10:02:27.6459100s - ReadConfig: Found provider 'NtpServer':
154483 10:02:27.6459486s - ReadConfig: 'InputProvider'=0x00000000
154483 10:02:27.6459634s - ReadConfig: 'MetaDataProvider'=0x00000000
154483 10:02:27.6459812s - ReadConfig: 'DllName'='C:\Windows\system32\w32time.dll'
154483 10:02:27.6459905s - ReadConfig: 'DllName'='C:\Windows\system32\w32time.dll'
154483 10:02:27.6459985s - ReadConfig: 'DllName'='C:\Windows\system32\w32time.dll'
154483 10:02:27.6460160s - ReadConfig: Found provider 'PtpClient':
154483 10:02:27.6460464s - ReadConfig: 'InputProvider'=0x00000001
154483 10:02:27.6460590s - ReadConfig: 'MetaDataProvider'=0x00000000
154483 10:02:27.6460717s - ReadConfig: 'DllName'='%systemroot%\system32\ptpprov.dll'
154483 10:02:27.6460810s - ReadConfig: 'DllName'='C:\Windows\system32\ptpprov.dll'
154483 10:02:27.6460888s - ReadConfig: 'DllName'='C:\Windows\system32\ptpprov.dll'
154483 10:02:27.6461067s - ReadConfig: Found provider 'VMICTimeProvider':
154483 10:02:27.6461374s - ReadConfig: 'InputProvider'=0x00000001
154483 10:02:27.6461532s - ReadConfig: 'MetaDataProvider'=0x00000000
154483 10:02:27.6461692s - ReadConfig: 'DllName'='C:\Windows\System32\vmictimeprovider.dll'
154483 10:02:27.6461779s - ReadConfig: 'DllName'='C:\Windows\System32\vmictimeprovider.dll'
154483 10:02:27.6462243s - ReadConfig: 'DllName'='C:\Windows\System32\vmictimeprovider.dll'
154483 10:02:27.6463786s - ReadConfig: 'PhaseCorrectRate'=0x00000001 (2)
154483 10:02:27.6463954s - ReadConfig: 'UpdateInterval'=0x00000064 (2)
154483 10:02:27.6464092s - ReadConfig: 'FrequencyCorrectRate'=0x00000002 (2)
154483 10:02:27.6464238s - ReadConfig: 'PollAdjustFactor'=0x00000005 (2)
154483 10:02:27.6464384s - ReadConfig: 'LargePhaseOffset'=0x02FAF080 (2)
154483 10:02:27.6464527s - ReadConfig: 'SpikeWatchPeriod'=0x00000384 (2)
154483 10:02:27.6464665s - ReadConfig: 'HoldPeriod'=0x00000005 (2)
154483 10:02:27.6464820s - ReadConfig: 'MinPollInterval'=0x00000006 (2)
154483 10:02:27.6464952s - ReadConfig: 'MaxPollInterval'=0x00000006 (2)
154483 10:02:27.6465090s - ReadConfig: 'ClockHoldoverPeriod'=0x00001E78 (2)
154483 10:02:27.6465224s - ReadConfig: 'AnnounceFlags'=0x0000000A (2)
154483 10:02:27.6465364s - ReadConfig: 'LocalClockDispersion'=0x0000000A (2)
154483 10:02:27.6465497s - ReadConfig: 'MaxNegPhaseCorrection'=0x0000D2F0 (2)
154483 10:02:27.6465635s - ReadConfig: 'MaxPosPhaseCorrection'=0x0000D2F0 (2)
154483 10:02:27.6465770s - ReadConfig: 'EventLogFlags'=0x00000002 (2)
154483 10:02:27.6465907s - ReadConfig: 'MaxAllowedPhaseOffset'=0x00000001 (2)
154483 10:02:27.6466035s - ReadConfig: 'UtilizeSslTimeData'=0x00000001 (2)
154483 10:02:27.6466175s - ReadConfig: 'ClockAdjustmentAuditLimit'=0x00000320 (2)
154483 10:02:27.6466337s - ReadConfig: 'TimeJumpAuditOffset'=0x00007080 (2)
154483 10:02:27.6466495s - ReadConfig: 'RpcInitFailureAction'=0x00000000 (1)
154483 10:02:27.6466626s - Clock adjustment info: dwCurrentSecPerTick: 156250 dwDefaultSecPerTick: 156250 bSyncToCmosDisabled:1
154483 10:02:27.6466741s - PerfFreq:10000000c/s
154483 10:02:27.6467043s - currAdj:10000000 Incr:10000000 IncrEnabled:1 CRCS:113.333 CRCI:66.6667
154483 10:02:27.6467966s - eLSState changed. Old State:0. New State:1
154483 10:02:27.6468354s - lastClockRate=156250, clockFrequency:10000000 clockPrecision=-23
154483 10:02:27.6470636s - SetTimeSlipNotification succeeds with 0x00000000.
154483 10:02:27.6489294s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:27.6491704s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:27.6498769s - DomainHierarchy: LSA role change notification. Redetecting.
154483 10:02:27.6513718s - ClockDisciplineThread: Starting: SetUnsync: LI:3 S:0 RDl:0 RDs:0 TSF:0x0
154483 10:02:27.6515399s - Starting Providers.
154483 10:02:27.6515581s - Starting 'PtpClient', dll:'C:\Windows\system32\ptpprov.dll'
154483 10:02:27.6530482s - LoadLibrary
154483 10:02:27.6723603s - Logging Info: Time provider 'PtpClient' has started successfully
154483 10:02:27.6723721s - Successfully started 1 providers.
154483 10:02:27.6737028s - UpdateTimerQueue1: TN:82960000::: LRT:0 LUT:82650000 LAFLTNS:0 TSLGT:0 LTNS:864000000000
154483 10:02:27.6737203s - W32TmServiceMain: waiting i16.000s (64.000s)
154483 10:02:27.6740038s - RPC Call - Query Configuration
154483 10:02:27.6740280s - RPC Call - Query Provider Configuration
154483 10:02:27.6740474s - RPC Call - Query Provider Configuration
154483 10:02:27.6740611s - RPC Call - Query Provider Configuration
154483 10:02:27.6740737s - RPC Call - Query Provider Configuration
154483 10:02:27.6743307s - A net topo refresh request already pending. Ignoring this notification
154483 10:02:27.6743693s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:27.6743865s - A net topo refresh request already pending. Ignoring this notification
154483 10:02:27.6744046s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:28.3750506s - A net topo refresh request already pending. Ignoring this notification
154483 10:02:28.3750884s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:28.6417815s - Network Topology Change
154483 10:02:28.6582118s - UpdateTimerQueue1: TN:92810000::: LRT:92650000 LUT:82650000 LAFLTNS:160000 TSLGT:9680423 LTNS:864000000000
154483 10:02:28.6582243s - W32TmServiceMain: waiting i15.031s (63.031s)
154483 10:02:29.8661627s - A net topo refresh will run in 45000 milliseconds
154483 10:02:29.8662067s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:29.9531483s - A net topo refresh request already pending. Ignoring this notification
154483 10:02:29.9531879s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:31.8287072s - A net topo refresh request already pending. Ignoring this notification
154483 10:02:31.8287490s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:31.8336315s - A net topo refresh request already pending. Ignoring this notification
154483 10:02:31.8336682s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:34.8685920s - A net topo refresh request already pending. Ignoring this notification
154483 10:02:34.8686699s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:36.8795941s - A net topo refresh request already pending. Ignoring this notification
154483 10:02:36.8796515s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
154483 10:02:43.6914037s - W32TmServiceMain: timeout
154483 10:02:43.6914710s - TSI_PhaseOffset returned:64530937760
154483 10:02:43.6915065s - UpdateTimerQueue1: TN:243120000::: LRT:92650000 LUT:82650000 LAFLTNS:150470000 TSLGT:160012647 LTNS:864000000000
154483 10:02:43.6915271s - W32TmServiceMain: waiting 64.000s
154483 10:02:53.5329246s - W32TmServiceMain: resync req, irreg now pending.
154483 10:02:53.5329887s - UpdateTimerQueue1: TN:341560000::: LRT:92650000 LUT:82650000 LAFLTNS:248910000 TSLGT:258426618 LTNS:864000000000
154483 10:02:53.5330155s - W32TmServiceMain: waiting i6.158s (54.158s)
154483 10:02:54.5327077s - W32TmServiceMain: resync req, irreg already pending.
154483 10:02:54.5327428s - UpdateTimerQueue1: TN:351560000::: LRT:92650000 LUT:82650000 LAFLTNS:258910000 TSLGT:268423457 LTNS:864000000000
154483 10:02:54.5327553s - W32TmServiceMain: waiting i5.158s (53.158s)
154483 10:02:55.5324418s - W32TmServiceMain: resync req, irreg already pending.
154483 10:02:55.5325087s - UpdateTimerQueue1: TN:361560000::: LRT:92650000 LUT:82650000 LAFLTNS:268910000 TSLGT:278419642 LTNS:864000000000
154483 10:02:55.5325342s - W32TmServiceMain: waiting i4.159s (52.159s)
154483 10:02:56.5321725s - W32TmServiceMain: resync req, irreg already pending.
154483 10:02:56.5322272s - UpdateTimerQueue1: TN:371560000::: LRT:92650000 LUT:82650000 LAFLTNS:278910000 TSLGT:288416012 LTNS:864000000000
154483 10:02:56.5322500s - W32TmServiceMain: waiting i3.159s (51.159s)
154483 10:02:57.5325424s - W32TmServiceMain: resync req, irreg already pending.
154483 10:02:57.5326038s - UpdateTimerQueue1: TN:381560000::: LRT:92650000 LUT:82650000 LAFLTNS:288910000 TSLGT:298418924 LTNS:864000000000
154483 10:02:57.5326292s - W32TmServiceMain: waiting i2.159s (50.159s)
154483 10:02:58.5322676s - W32TmServiceMain: resync req, irreg already pending.
154483 10:02:58.5323238s - UpdateTimerQueue1: TN:391560000::: LRT:92650000 LUT:82650000 LAFLTNS:298910000 TSLGT:308415272 LTNS:864000000000
154483 10:02:58.5323466s - W32TmServiceMain: waiting i1.159s (49.159s)
154483 10:02:59.5320573s - W32TmServiceMain: resync req, irreg already pending.
154483 10:02:59.5321181s - UpdateTimerQueue1: TN:401560000::: LRT:92650000 LUT:82650000 LAFLTNS:308910000 TSLGT:318412368 LTNS:864000000000
154483 10:02:59.5321440s - W32TmServiceMain: waiting i0.160s (48.160s)
154483 10:02:59.7038808s - W32TmServiceMain: timeout
154483 10:02:59.7039371s - TSI_PhaseOffset returned:64529887424
154483 10:02:59.7040634s - PtpClient returned 1 samples.
154483 10:02:59.7040962s - Intersection successful with 0 dropped samples.
154483 10:02:59.7041164s - 0: Sample:0 SyncDist:320001669 SelectDisp:0
154483 10:02:59.7041358s - Sample 0 chosen. Select Dispersion:00.0000000s SPHO:0 STC:2581
154483 10:02:59.7041616s - Sample 0 offset:-00.3033841s delay:+00.0003298s dispersion:00.0000020s
PCT: 2052 154483 10:02:59.7042926s - ClockDispln Update: SO:-3033841 KPhO:0 spO:64531985872 PhO:-3033841 uT:2053
SD:10 LI:0 S:3 RDl:3298 RDs:100020 TSF:0x0
Unset->Hold
154483 10:02:59.7046384s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-1 CRD:-1 PhCRR_:0 CRD_:0 CR:10000000 (PhCRRL:-1 CRL:156250 phcTL:2052) UI:100 KPhO:-3033841
154483 10:02:59.7048056s - Logging information: The time service is now synchronizing the system time with the time source 10.0.1.251.
154483 10:02:59.7048492s - UpdateTimerQueue1: TN:403280000::: LRT:92650000 LUT:82650000 LAFLTNS:0 TSLGT:0 LTNS:78000000000
154483 10:02:59.7048610s - W32TmServiceMain: waiting 64.000s
154483 10:03:00.5326261s - W32TmServiceMain: resync req, irreg now pending.
154483 10:03:00.5326896s - UpdateTimerQueue1: TN:411560000::: LRT:92650000 LUT:82650000 LAFLTNS:8277722 TSLGT:8277722 LTNS:78000000000
154483 10:03:00.5327155s - W32TmServiceMain: waiting i15.172s (63.172s)
PCT: 64 154483 10:03:00.7045640s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-189615 CRD:-189615 PhCRR_:-1 CRD_:-1 CR:10000000 (PhCRRL:-189615 CRL:156250 phcTL:64) UI:100 KPhO:-3033840
154483 10:03:01.5170287s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:01.5170713s - UpdateTimerQueue1: TN:421560000::: LRT:92650000 LUT:82650000 LAFLTNS:18120792 TSLGT:18120792 LTNS:78000000000
154483 10:03:01.5170853s - W32TmServiceMain: waiting i14.187s (62.187s)
PCT: 65 154483 10:03:01.7009695s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-177764 CRD:-177764 PhCRR_:-189615 CRD_:-189615 CR:10000000 (PhCRRL:-177764 CRL:156250 phcTL:65) UI:100 KPhO:-2844225
154483 10:03:02.4990670s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:02.4991228s - UpdateTimerQueue1: TN:431560000::: LRT:92650000 LUT:82650000 LAFLTNS:27940669 TSLGT:27940669 LTNS:78000000000
154483 10:03:02.4991616s - W32TmServiceMain: waiting i13.205s (61.205s)
PCT: 65 154483 10:03:02.6986461s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-166653 CRD:-166653 PhCRR_:-177764 CRD_:-177764 CR:10000000 (PhCRRL:-166653 CRL:156250 phcTL:65) UI:100 KPhO:-2666461
154483 10:03:03.4822406s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:03.4822965s - UpdateTimerQueue1: TN:441560000::: LRT:92650000 LUT:82650000 LAFLTNS:37771504 TSLGT:37771504 LTNS:78000000000
154483 10:03:03.4823197s - W32TmServiceMain: waiting i12.222s (60.222s)
PCT: 65 154483 10:03:03.6973452s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-156238 CRD:-156238 PhCRR_:-166653 CRD_:-166653 CR:10000000 (PhCRRL:-156238 CRL:156250 phcTL:65) UI:100 KPhO:-2499808
154483 10:03:04.4664202s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:04.4664761s - UpdateTimerQueue1: TN:451560000::: LRT:92650000 LUT:82650000 LAFLTNS:47612491 TSLGT:47612491 LTNS:78000000000
154483 10:03:04.4665009s - W32TmServiceMain: waiting i11.238s (59.238s)
PCT: 65 154483 10:03:04.6971517s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-146473 CRD:-146473 PhCRR_:-156238 CRD_:-156238 CR:10000000 (PhCRRL:-146473 CRL:156250 phcTL:65) UI:100 KPhO:-2343570
154483 10:03:05.4514627s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:05.4515345s - UpdateTimerQueue1: TN:461560000::: LRT:92650000 LUT:82650000 LAFLTNS:57462085 TSLGT:57462085 LTNS:78000000000
154483 10:03:05.4515452s - W32TmServiceMain: waiting i10.253s (58.253s)
PCT: 65 154483 10:03:05.6978470s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-137318 CRD:-137318 PhCRR_:-146473 CRD_:-146473 CR:10000000 (PhCRRL:-137318 CRL:156250 phcTL:65) UI:100 KPhO:-2197097
154483 10:03:06.4375095s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:06.4375679s - UpdateTimerQueue1: TN:471560000::: LRT:92650000 LUT:82650000 LAFLTNS:67321794 TSLGT:67321794 LTNS:78000000000
154483 10:03:06.4375926s - W32TmServiceMain: waiting i9.267s (57.267s)
PCT: 65 154483 10:03:06.6994790s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-128736 CRD:-128736 PhCRR_:-137318 CRD_:-137318 CR:10000000 (PhCRRL:-128736 CRL:156250 phcTL:65) UI:100 KPhO:-2059779
154483 10:03:07.4243561s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:07.4244260s - UpdateTimerQueue1: TN:481560000::: LRT:92650000 LUT:82650000 LAFLTNS:77189412 TSLGT:77189412 LTNS:78000000000
154483 10:03:07.4244548s - W32TmServiceMain: waiting i8.281s (56.281s)
PCT: 65 154483 10:03:07.7018774s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-120690 CRD:-120690 PhCRR_:-128736 CRD_:-128736 CR:10000000 (PhCRRL:-120690 CRL:156250 phcTL:65) UI:100 KPhO:-1931043
154483 10:03:08.4087699s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:08.4088314s - UpdateTimerQueue1: TN:491560000::: LRT:92650000 LUT:82650000 LAFLTNS:87032556 TSLGT:87032556 LTNS:78000000000
154483 10:03:08.4088571s - W32TmServiceMain: waiting i7.296s (55.296s)
PCT: 65 154483 10:03:08.7020416s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-113147 CRD:-113147 PhCRR_:-120690 CRD_:-120690 CR:10000000 (PhCRRL:-113147 CRL:156250 phcTL:65) UI:100 KPhO:-1810353
154483 10:03:09.3971664s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:09.3972209s - UpdateTimerQueue1: TN:501560000::: LRT:92650000 LUT:82650000 LAFLTNS:96915617 TSLGT:96915617 LTNS:78000000000
154483 10:03:09.3972457s - W32TmServiceMain: waiting i6.308s (54.308s)
PCT: 65 154483 10:03:09.7060454s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-106075 CRD:-106075 PhCRR_:-113147 CRD_:-113147 CR:10000000 (PhCRRL:-106075 CRL:156250 phcTL:65) UI:100 KPhO:-1697206
154483 10:03:10.3862213s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:10.3862804s - UpdateTimerQueue1: TN:511560000::: LRT:92650000 LUT:82650000 LAFLTNS:106805352 TSLGT:106805352 LTNS:78000000000
154483 10:03:10.3863054s - W32TmServiceMain: waiting i5.319s (53.319s)
PCT: 65 154483 10:03:10.7108101s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-99445 CRD:-99445 PhCRR_:-106075 CRD_:-106075 CR:10000000 (PhCRRL:-99445 CRL:156250 phcTL:65) UI:100 KPhO:-1591131
154483 10:03:11.3758731s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:11.3759298s - UpdateTimerQueue1: TN:521560000::: LRT:92650000 LUT:82650000 LAFLTNS:116700994 TSLGT:116700994 LTNS:78000000000
154483 10:03:11.3760583s - W32TmServiceMain: waiting i4.329s (52.329s)
PCT: 65 154483 10:03:11.7161981s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-93230 CRD:-93230 PhCRR_:-99445 CRD_:-99445 CR:10000000 (PhCRRL:-93230 CRL:156250 phcTL:65) UI:100 KPhO:-1491686
154483 10:03:12.3816252s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:12.3816849s - UpdateTimerQueue1: TN:531710000::: LRT:92650000 LUT:82650000 LAFLTNS:126756576 TSLGT:126756576 LTNS:78000000000
154483 10:03:12.3817082s - W32TmServiceMain: waiting i3.324s (51.324s)
PCT: 65 154483 10:03:12.7221770s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-87403 CRD:-87403 PhCRR_:-93230 CRD_:-93230 CR:10000000 (PhCRRL:-87403 CRL:156250 phcTL:65) UI:100 KPhO:-1398456
154483 10:03:13.3724547s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:13.3724872s - UpdateTimerQueue1: TN:541710000::: LRT:92650000 LUT:82650000 LAFLTNS:136663976 TSLGT:136663976 LTNS:78000000000
154483 10:03:13.3724964s - W32TmServiceMain: waiting i2.333s (50.333s)
PCT: 65 154483 10:03:13.7287666s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-81940 CRD:-81940 PhCRR_:-87403 CRD_:-87403 CR:10000000 (PhCRRL:-81940 CRL:156250 phcTL:65) UI:100 KPhO:-1311053
154483 10:03:14.3640210s - W32TmServiceMain: resync req, irreg already pending.
154483 10:03:14.3640751s - UpdateTimerQueue1: TN:551710000::: LRT:92650000 LUT:82650000 LAFLTNS:146579286 TSLGT:146579286 LTNS:78000000000
154483 10:03:14.3640875s - W32TmServiceMain: waiting i1.342s (49.342s)
154483 10:03:14.6893461s - Network Topology Change
154483 10:03:14.7076452s - UpdateTimerQueue1: TN:555150000::: LRT:555000000 LUT:82650000 LAFLTNS:150000 TSLGT:149831617 LTNS:78000000000
154483 10:03:14.7076541s - W32TmServiceMain: waiting i1.016s (49.016s)
PCT: 65 154483 10:03:14.7359276s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-76819 CRD:-76819 PhCRR_:-81940 CRD_:-81940 CR:10000000 (PhCRRL:-76819 CRL:156250 phcTL:65) UI:100 KPhO:-1229113
154483 10:03:15.7279246s - W32TmServiceMain: timeout
154483 10:03:15.7279926s - TSI_PhaseOffset returned:64528839584
154483 10:03:15.7280369s - UpdateTimerQueue1: TN:565460000::: LRT:555000000 LUT:82650000 LAFLTNS:10460000 TSLGT:160034811 LTNS:78000000000
154483 10:03:15.7280446s - W32TmServiceMain: waiting 47.996s
PCT: 65 154483 10:03:15.7435508s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-72018 CRD:-72018 PhCRR_:-76819 CRD_:-76819 CR:10000000 (PhCRRL:-72018 CRL:156250 phcTL:65) UI:100 KPhO:-1152294
PCT: 65 154483 10:03:16.7516741s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-67517 CRD:-67517 PhCRR_:-72018 CRD_:-72018 CR:10000000 (PhCRRL:-67517 CRL:156250 phcTL:65) UI:100 KPhO:-1080276
PCT: 65 154483 10:03:17.7602292s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-63297 CRD:-63297 PhCRR_:-67517 CRD_:-67517 CR:10000000 (PhCRRL:-63297 CRL:156250 phcTL:65) UI:100 KPhO:-1012759
PCT: 65 154483 10:03:18.7692576s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-59341 CRD:-59341 PhCRR_:-63297 CRD_:-63297 CR:10000000 (PhCRRL:-59341 CRL:156250 phcTL:65) UI:100 KPhO:-949462
PCT: 65 154483 10:03:19.7786790s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-55632 CRD:-55632 PhCRR_:-59341 CRD_:-59341 CR:10000000 (PhCRRL:-55632 CRL:156250 phcTL:65) UI:100 KPhO:-890121
PCT: 65 154483 10:03:20.7884302s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-52155 CRD:-52155 PhCRR_:-55632 CRD_:-55632 CR:10000000 (PhCRRL:-52155 CRL:156250 phcTL:65) UI:100 KPhO:-834489
PCT: 65 154483 10:03:21.7985463s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-48895 CRD:-48895 PhCRR_:-52155 CRD_:-52155 CR:10000000 (PhCRRL:-48895 CRL:156250 phcTL:65) UI:100 KPhO:-782334
PCT: 65 154483 10:03:22.8089893s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-45839 CRD:-45839 PhCRR_:-48895 CRD_:-48895 CR:10000000 (PhCRRL:-45839 CRL:156250 phcTL:65) UI:100 KPhO:-733439
PCT: 65 154483 10:03:23.8198946s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-42975 CRD:-42975 PhCRR_:-45839 CRD_:-45839 CR:10000000 (PhCRRL:-42975 CRL:156250 phcTL:65) UI:100 KPhO:-687600
PCT: 65 154483 10:03:24.8308841s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-40289 CRD:-40289 PhCRR_:-42975 CRD_:-42975 CR:10000000 (PhCRRL:-40289 CRL:156250 phcTL:65) UI:100 KPhO:-644625
PCT: 65 154483 10:03:25.8421838s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-37771 CRD:-37771 PhCRR_:-40289 CRD_:-40289 CR:10000000 (PhCRRL:-37771 CRL:156250 phcTL:65) UI:100 KPhO:-604336
PCT: 65 154483 10:03:26.8537684s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-35410 CRD:-35410 PhCRR_:-37771 CRD_:-37771 CR:10000000 (PhCRRL:-35410 CRL:156250 phcTL:65) UI:100 KPhO:-566565
PCT: 65 154483 10:03:27.8655936s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-33197 CRD:-33197 PhCRR_:-35410 CRD_:-35410 CR:10000000 (PhCRRL:-33197 CRL:156250 phcTL:65) UI:100 KPhO:-531155
PCT: 64 154483 10:03:28.8680553s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-31122 CRD:-31122 PhCRR_:-33197 CRD_:-33197 CR:10000000 (PhCRRL:-31122 CRL:156250 phcTL:64) UI:100 KPhO:-497958
PCT: 65 154483 10:03:29.8802002s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-29177 CRD:-29177 PhCRR_:-31122 CRD_:-31122 CR:10000000 (PhCRRL:-29177 CRL:156250 phcTL:65) UI:100 KPhO:-466836
PCT: 64 154483 10:03:30.8820002s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-27353 CRD:-27353 PhCRR_:-29177 CRD_:-29177 CR:10000000 (PhCRRL:-27353 CRL:156250 phcTL:64) UI:100 KPhO:-437659
PCT: 65 154483 10:03:31.8946251s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-25644 CRD:-25644 PhCRR_:-27353 CRD_:-27353 CR:10000000 (PhCRRL:-25644 CRL:156250 phcTL:65) UI:100 KPhO:-410306
PCT: 65 154483 10:03:32.9073844s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-24041 CRD:-24041 PhCRR_:-25644 CRD_:-25644 CR:10000000 (PhCRRL:-24041 CRL:156250 phcTL:65) UI:100 KPhO:-384662
PCT: 65 154483 10:03:33.9203566s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-22538 CRD:-22538 PhCRR_:-24041 CRD_:-24041 CR:10000000 (PhCRRL:-22538 CRL:156250 phcTL:65) UI:100 KPhO:-360621
PCT: 65 154483 10:03:34.9334220s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-21130 CRD:-21130 PhCRR_:-22538 CRD_:-22538 CR:10000000 (PhCRRL:-21130 CRL:156250 phcTL:65) UI:100 KPhO:-338083
PCT: 65 154483 10:03:35.9468407s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-19809 CRD:-19809 PhCRR_:-21130 CRD_:-21130 CR:10000000 (PhCRRL:-19809 CRL:156250 phcTL:65) UI:100 KPhO:-316953
PCT: 65 154483 10:03:36.9601829s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-18571 CRD:-18571 PhCRR_:-19809 CRD_:-19809 CR:10000000 (PhCRRL:-18571 CRL:156250 phcTL:65) UI:100 KPhO:-297144
PCT: 65 154483 10:03:37.9736595s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-17410 CRD:-17410 PhCRR_:-18571 CRD_:-18571 CR:10000000 (PhCRRL:-17410 CRL:156250 phcTL:65) UI:100 KPhO:-278573
PCT: 65 154483 10:03:38.9873105s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-16322 CRD:-16322 PhCRR_:-17410 CRD_:-17410 CR:10000000 (PhCRRL:-16322 CRL:156250 phcTL:65) UI:100 KPhO:-261163
154483 10:03:39.2523591s - W32TmServiceMain: resync req, irreg now pending.
154483 10:03:39.2524128s - UpdateTimerQueue1: TN:801560000::: LRT:555000000 LUT:82650000 LAFLTNS:246560000 TSLGT:395278026 LTNS:78000000000
154483 10:03:39.2524353s - W32TmServiceMain: waiting i0.000s (24.472s)
154483 10:03:39.2678906s - W32TmServiceMain: timeout
154483 10:03:39.2679445s - TSI_PhaseOffset returned:64530937760
154483 10:03:39.2679769s - PtpClient returned 1 samples.
154483 10:03:39.2679980s - Intersection successful with 0 dropped samples.
154483 10:03:39.2680176s - 0: Sample:0 SyncDist:320001788 SelectDisp:0
154483 10:03:39.2680447s - Sample 0 chosen. Select Dispersion:00.0000000s SPHO:-2772678 STC:5131
154483 10:03:39.2680709s - Sample 0 offset:-00.0250290s delay:+00.0003537s dispersion:00.0000020s
PCT: 18 154483 10:03:39.2681383s - ClockDispln Update: SO:-250290 KPhO:-261163 spO:64531985872 PhO:10873 uT:2550
154483 10:03:39.2682212s - sysPollMinUpdates:64 PO:10873 SO: -250290 FllDown:39.8438 PllUp:39.8438 PllDown:256 FllRA:1.36445e-005 PllRA:-152.168 CR:10000000 UUR:-0.168141
UUR:-0.168141 UCRA:-152 RA:-152 CR:10000152 CRL:156252 DecRA:-0.168141 RACV:25000 nT:18446744073709551615 RAPhO:0 kPHO:-250290 SD:14 (i) LI:0 S:3 RDl:3537 RDs:100020 TSF:0x0
Hold(0)
154483 10:03:39.2685195s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-15643 CRD:-15643 PhCRR_:-16322 CRD_:-16322 CR:10000152 (PhCRRL:-15643 CRL:156252 phcTL:18) UI:100 KPhO:-250290
154483 10:03:39.2686430s - UpdateTimerQueue1: TN:801710000::: LRT:555000000 LUT:82650000 LAFLTNS:0 TSLGT:0 LTNS:78000000000
154483 10:03:39.2686969s - W32TmServiceMain: waiting 24.456s
PCT: 65 154483 10:03:40.2818137s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-14665 CRD:-14665 PhCRR_:-15643 CRD_:-15643 CR:10000152 (PhCRRL:-14665 CRL:156252 phcTL:65) UI:100 KPhO:-234647
PCT: 65 154483 10:03:41.2956819s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-13748 CRD:-13748 PhCRR_:-14665 CRD_:-14665 CR:10000152 (PhCRRL:-13748 CRL:156252 phcTL:65) UI:100 KPhO:-219982
154483 10:03:42.2472637s - W32TmServiceMain: resync req, reg too soon.
154483 10:03:42.2473235s - UpdateTimerQueue1: TN:831560000::: LRT:555000000 LUT:82650000 LAFLTNS:29785615 TSLGT:29785615 LTNS:78000000000
154483 10:03:42.2473481s - W32TmServiceMain: waiting 21.478s
PCT: 65 154483 10:03:42.3096980s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-12889 CRD:-12889 PhCRR_:-13748 CRD_:-13748 CR:10000152 (PhCRRL:-12889 CRL:156252 phcTL:65) UI:100 KPhO:-206234
PCT: 65 154483 10:03:43.3237574s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-12084 CRD:-12084 PhCRR_:-12889 CRD_:-12889 CR:10000152 (PhCRRL:-12084 CRL:156252 phcTL:65) UI:100 KPhO:-193345
PCT: 65 154483 10:03:44.3378438s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-11328 CRD:-11328 PhCRR_:-12084 CRD_:-12084 CR:10000152 (PhCRRL:-11328 CRL:156252 phcTL:65) UI:100 KPhO:-181261
PCT: 65 154483 10:03:45.3521060s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-10620 CRD:-10620 PhCRR_:-11328 CRD_:-11328 CR:10000152 (PhCRRL:-10620 CRL:156252 phcTL:65) UI:100 KPhO:-169934
PCT: 65 154483 10:03:46.3663894s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-9957 CRD:-9957 PhCRR_:-10620 CRD_:-10620 CR:10000152 (PhCRRL:-9957 CRL:156252 phcTL:65) UI:100 KPhO:-159314
154483 10:03:47.2558445s - W32TmServiceMain: resync req, reg too soon.
154483 10:03:47.2559047s - UpdateTimerQueue1: TN:881710000::: LRT:555000000 LUT:82650000 LAFLTNS:79870549 TSLGT:79870549 LTNS:78000000000
154483 10:03:47.2559271s - W32TmServiceMain: waiting 16.469s