microsoft / W32Time

This repo provides resources for high accuracy time on Windows
MIT License
71 stars 23 forks source link

PTP client operational, yet system time is wrong #20

Open dcnieho opened 9 months ago

dcnieho commented 9 months ago

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 ```