Server 2012 W32time NTP synchronization delay Hyper-V

bigbangtech
bigbangtech used Ask the Experts™
on
I manually set server 2012 to synchronize to an external NTP server per microsoft's instructions, and to sync every 900 secs (15 minutes)

After a restart, running w32tm /query /source returns "local cmos clock"

w32tm /query /peers shows the 4 ntp servers I configured as pending, with a countdown from 900 seconds.

After 900 seconds, finally the peers are accepted as a time source. Why doesn't this happen during startup?

w32tm /monitor is able to get valid time
Comment
Watch Question

Do more with

Expert Office
EXPERT OFFICE® is a registered trademark of EXPERTS EXCHANGE®

Author

Commented:
I've attached a w32tm log file showing all activity before the 900 resync period times out when the peers become active

151644 19:48:19.3898138s - ---------- Log File Opened -----------------
151644 19:48:19.3898138s - CurSpc:15625000ns  BaseSpc:15625000ns  SyncToCmos:Yes
151644 19:48:19.3898138s - PerfFreq:10000000c/s
151644 19:48:19.3898138s - ReadConfig: Found provider 'NtpClient':
151644 19:48:19.3898138s - ReadConfig:   'Enabled'=0x00000001
151644 19:48:19.3898138s - ReadConfig:   'DllName'='C:\Windows\system32\w32time.DLL'
151644 19:48:19.3898138s - ReadConfig:   'DllName'='C:\Windows\system32\w32time.DLL'
151644 19:48:19.3898138s - ReadConfig:   'DllName'='C:\Windows\system32\w32time.DLL'
151644 19:48:19.3898138s - ReadConfig:   'InputProvider'=0x00000001
151644 19:48:19.3898138s - ReadConfig:   'RunOnVirtualOnly'=0x00000000
151644 19:48:19.3898138s - ReadConfig: Found provider 'NtpServer':
151644 19:48:19.3898138s - ReadConfig:   'Enabled'=0x00000001
151644 19:48:19.3898138s - ReadConfig:   'DllName'='C:\Windows\system32\w32time.DLL'
151644 19:48:19.3898138s - ReadConfig:   'DllName'='C:\Windows\system32\w32time.DLL'
151644 19:48:19.3898138s - ReadConfig:   'DllName'='C:\Windows\system32\w32time.DLL'
151644 19:48:19.3898138s - ReadConfig:   'InputProvider'=0x00000000
151644 19:48:19.3898138s - ReadConfig:   'RunOnVirtualOnly'=0x00000000
151644 19:48:19.3898138s - ReadConfig: Found provider 'VMICTimeProvider':
151644 19:48:19.3898138s - ReadConfig:   'Enabled'=0x00000000
151644 19:48:19.3898138s - ReadConfig:   'DllName'='C:\Windows\System32\vmictimeprovider.dll'
151644 19:48:19.3898138s - ReadConfig:   'DllName'='C:\Windows\System32\vmictimeprovider.dll'
151644 19:48:19.3898138s - ReadConfig:   'DllName'='C:\Windows\System32\vmictimeprovider.dll'
151644 19:48:19.3898138s - ReadConfig:   'InputProvider'=0x00000001
151644 19:48:19.3898138s - ReadConfig:   'RunOnVirtualOnly'=0x00000001
151644 19:48:19.3898138s - ReadConfig: 'PhaseCorrectRate'=0x00000001 (2)
151644 19:48:19.3898138s - ReadConfig: 'UpdateInterval'=0x00057E40 (2)
151644 19:48:19.3898138s - ReadConfig: 'FrequencyCorrectRate'=0x00000004 (2)
151644 19:48:19.3898138s - ReadConfig: 'PollAdjustFactor'=0x00000005 (2)
151644 19:48:19.3898138s - ReadConfig: 'LargePhaseOffset'=0x02FAF080 (2)
151644 19:48:19.3898138s - ReadConfig: 'SpikeWatchPeriod'=0x00000384 (2)
151644 19:48:19.3898138s - ReadConfig: 'HoldPeriod'=0x00000005 (2)
151644 19:48:19.3898138s - ReadConfig: 'MinPollInterval'=0x0000000A (2)
151644 19:48:19.3898138s - ReadConfig: 'MaxPollInterval'=0x0000000F (2)
151644 19:48:19.3898138s - ReadConfig: 'AnnounceFlags'=0x00000005 (2)
151644 19:48:19.3898138s - ReadConfig: 'LocalClockDispersion'=0x0000000A (2)
151644 19:48:19.3898138s - ReadConfig: 'MaxNegPhaseCorrection'=0x00000708 (2)
151644 19:48:19.3898138s - ReadConfig: 'MaxPosPhaseCorrection'=0x00000708 (2)
151644 19:48:19.3898138s - ReadConfig: 'EventLogFlags'=0x00000002 (2)
151644 19:48:19.3898138s - ReadConfig: 'MaxAllowedPhaseOffset'=0x00000001 (2)
151644 19:48:19.3898138s - ReadConfig: 'TimeJumpAuditOffset'=0x00007080 (2)
151644 19:48:19.3898138s - lastClockRate=156250, clockPrecision=-6
151644 19:48:19.3898138s - SetTimeSlipNotification succeeds with 0x00000000.
151644 19:48:19.3898138s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
151644 19:48:19.3898138s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
151644 19:48:19.3898138s -   DomainHierarchy: LSA role change notification. Redetecting.
151644 19:48:19.3898138s - ClockDisciplineThread: Starting: SetUnsync: LI:0 S:1 RDl:0 RDs:100000000 TSF:0x0 
151644 19:48:19.3898138s - ClockDispln: we're a reliable time service with no time source: LS: 0, TN: 864000000000, WAIT: 86400000
151644 19:48:19.3898138s - Starting Providers.
151644 19:48:19.3898138s - Starting 'NtpClient', dll:'C:\Windows\system32\w32time.DLL'
151644 19:48:19.3898138s - LoadLibrary
151644 19:48:19.3898138s - NtpTimeProvOpen("NtpClient") called.
151644 19:48:19.3898138s - StartNtpProv
151644 19:48:19.3898138s - sysPrecision=-6, systmeClockResolution=156250
151644 19:48:19.3898138s - NtpProvider: Created 2 sockets (0 listen-only): [::]:123<0x0>, 0.0.0.0:123<0x0>
151644 19:48:19.3898138s - StartListeningThread completed!
151644 19:48:19.3898138s - PeerPollingThread: waiting forever
151644 19:48:19.3898138s - StartPeerPollingThread completed!
151644 19:48:19.3898138s - ReadConfig: 'AllowNonstandardModeCombinations'=0x00000001 (2)
151644 19:48:19.3898138s - ReadConfig: 'CompatibilityFlags'=0x80000000 (2)
151644 19:48:19.3898138s - ReadConfig: 'SpecialPollInterval'=0x00000384 (2)
151644 19:48:19.3898138s - ReadConfig: 'ResolvePeerBackoffMinutes'=0x0000000F (2)
151644 19:48:19.3898138s - ReadConfig: 'ResolvePeerBackoffMaxTimes'=0x00000007 (2)
151644 19:48:19.3898138s - ReadConfig: 'EventLogFlags'=0x00000001 (2)
151644 19:48:19.3898138s - ReadConfig: 'LargeSampleSkew'=0x00000003 (2)
151644 19:48:19.3898138s - ReadConfig: 'SignatureAuthAllowed'=0x00000001 (2)
151644 19:48:19.3898138s - ReadConfig: 'Type'=NTP (2)
151644 19:48:19.3898138s - ReadConfig: 'NtpServer'=0.pool.ntp.org,0x1 1.pool.ntp.org,0x1 2.pool.ntp.org,0x1 3.pool.ntp.org,0x1 (2)
151644 19:48:19.3898138s - ReadConfig: 'ManualPeerList'(parsed)='0.pool.ntp.org,0x1', '1.pool.ntp.org,0x1', '2.pool.ntp.org,0x1', '3.pool.ntp.org,0x1'
151644 19:48:19.3898138s - AddNewPendingPeer: manual
151644 19:48:19.3898138s - AddNewPendingPeer: manual
151644 19:48:19.3898138s - AddNewPendingPeer: manual
151644 19:48:19.3898138s - AddNewPendingPeer: manual
151644 19:48:19.3898138s - StartListeningThread completed!
151644 19:48:19.3898138s - PeerPollingThread: waiting 400.611s
151644 19:48:19.3898138s - StartPeerPollingThread completed!
151644 19:48:19.3898138s - PeerPollingThread: PeerListUpdated
151644 19:48:19.3898138s - NtpClient started.
151644 19:48:19.3898138s - Starting 'NtpServer', dll:'C:\Windows\system32\w32time.DLL'
151644 19:48:19.3898138s - PeerPollingThread: waiting 400.611s
151644 19:48:19.3898138s - LoadLibrary
151644 19:48:19.3898138s - NtpTimeProvOpen("NtpServer") called.
151644 19:48:19.3898138s - ReadConfig: 'AllowNonstandardModeCombinations'=0x00000001 (2)
151644 19:48:19.3898138s - ReadConfig: 'EventLogFlags'=0x00000000 (0)
151644 19:48:19.3898138s - ReadConfig: 'UnsecureTimeSyncRequestsLogThrottlePeriod'=0x05265C00 (86400000)
151644 19:48:19.3898138s - ReadConfig: failed to open 'Software\Policies\Microsoft\W32Time\Config' key, treating as non-fatal
151644 19:48:19.3898138s - ReadConfig: 'RequireSecureTimeSyncRequests'=0x00000000 (2)
151644 19:48:19.3898138s - StartListeningThread completed!
151644 19:48:19.3898138s - PeerPollingThread: waiting 400.611s
151644 19:48:19.3898138s - StartPeerPollingThread completed!
151644 19:48:19.3898138s - NtpServer started.
151644 19:48:19.3898138s - Successfully started 2 providers.
151644 19:48:19.3898138s - W32TmServiceMain: waiting i16.000s (1024.000s)
151644 19:48:19.3898138s - W32TmServiceMain: Network Topology Change
151644 19:48:19.4835843s - W32TmServiceMain: Network Topology Change
151644 19:48:19.3898138s - TimeProvCommand([NtpClient], TPC_NetTopoChange) called.
151644 19:48:19.4835843s - TimeProvCommand([NtpClient], TPC_NetTopoChange) called.
151644 19:48:19.4835843s - NtpProvider: Network Topology Change
151644 19:48:19.4835843s -   Peer (special) now pending: <Name: poll:900 diff:499 last:131021124000000000 resync?:FALSE>
151644 19:48:19.4835843s -   Peer (special) now pending: <Name: poll:900 diff:499 last:131021124000000000 resync?:FALSE>
151644 19:48:19.4835843s -   Peer (special) now pending: <Name: poll:900 diff:499 last:131021124000000000 resync?:FALSE>
151644 19:48:19.4835843s -   Peer (special) now pending: <Name: poll:900 diff:499 last:131021124000000000 resync?:FALSE>
151644 19:48:19.4835843s -   Peers reset: p-p:4 a-p:4 a-x:0
151644 19:48:19.4835843s - NtpProvider: Created 2 sockets (0 listen-only): [::]:123<0x0>, 0.0.0.0:123<0x0>
151644 19:48:19.4835843s - StartListeningThread completed!
151644 19:48:19.4835843s - PeerPollingThread: waiting 400.517s
151644 19:48:19.4835843s - StartPeerPollingThread completed!
151644 19:48:19.4835843s - TimeProvCommand([NtpServer], TPC_NetTopoChange) called.
151644 19:48:19.4835843s - W32TmServiceMain: waiting i16.000s (1024.000s)
151644 19:48:19.4835843s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
151644 19:48:19.4835843s - PeerPollingThread: PeerListUpdated
151644 19:48:19.4835843s - PeerPollingThread: waiting 400.517s
151644 19:48:19.4835843s - NtpProvider: Network Topology Change
151644 19:48:19.4835843s -   Peer (special) now pending: <Name: poll:900 diff:499 last:131021124000000000 resync?:FALSE>
151644 19:48:19.4835843s -   Peer (special) now pending: <Name: poll:900 diff:499 last:131021124000000000 resync?:FALSE>
151644 19:48:19.4835843s -   Peer (special) now pending: <Name: poll:900 diff:499 last:131021124000000000 resync?:FALSE>
151644 19:48:19.4835843s -   Peer (special) now pending: <Name: poll:900 diff:499 last:131021124000000000 resync?:FALSE>
151644 19:48:19.4835843s -   Peers reset: p-p:4 a-p:4 a-x:0
151644 19:48:19.4835843s - NtpProvider: Created 2 sockets (0 listen-only): [::]:123<0x0>, 0.0.0.0:123<0x0>
151644 19:48:19.4835843s - StartListeningThread completed!
151644 19:48:19.4835843s - PeerPollingThread: waiting 400.517s
151644 19:48:19.4835843s - StartPeerPollingThread completed!
151644 19:48:19.4835843s - PeerPollingThread: PeerListUpdated
151644 19:48:19.4835843s - TimeProvCommand([NtpServer], TPC_NetTopoChange) called.
151644 19:48:19.4835843s - PeerPollingThread: waiting 400.517s
151644 19:48:19.4835843s - W32TmServiceMain: waiting i16.000s (1024.000s)
151644 19:48:19.4835843s - W32TmServiceMain: RequestNetTopoChangeNotification Succeed
151644 19:48:35.4854943s - W32TmServiceMain: timeout
151644 19:48:35.4854943s - W32TmServiceMain: waiting 1024.000s
151644 19:48:39.0763575s - RPC Caller is WIN-BUQU0KCEFJ7\Administrator (S-1-5-21-911935613-2242379459-4002355139-500)
151644 19:48:39.0763575s - RPC Call Attribute is local=1, kernel=0, session=0, authentication=6, protocol=2, OpNum=3
151644 19:48:39.0763575s - RPC Call - Query Source
151644 19:48:42.5429637s - RPC Caller is WIN-BUQU0KCEFJ7\Administrator (S-1-5-21-911935613-2242379459-4002355139-500)
151644 19:48:42.5429637s - RPC Call Attribute is local=1, kernel=0, session=0, authentication=6, protocol=3, OpNum=2
151644 19:55:00.0139184s - PeerPollingThread: WaitTimeout
151644 19:55:00.0139184s - Resolving manual peer: 0.pool.ntp.org,0x1
151644 19:55:00.1701656s - Association: (Local) 0.0.0.0:123 => 38.229.71.1:123 (Remote)
151644 19:55:00.1701656s - Association: (Local) 0.0.0.0:123 => 152.2.133.53:123 (Remote)
151644 19:55:00.1701656s - Association: (Local) 0.0.0.0:123 => 131.107.13.100:123 (Remote)
151644 19:55:00.1701656s - Association: (Local) 0.0.0.0:123 => 97.107.128.58:123 (Remote)
151644 19:55:00.1701656s - Created reachability group: (
151644 19:55:00.1701656s - 38.229.71.1:123,
151644 19:55:00.1701656s - 152.2.133.53:123,
151644 19:55:00.1701656s - 131.107.13.100:123,
151644 19:55:00.1701656s - 97.107.128.58:123,
151644 19:55:00.1701656s - )
151644 19:55:00.1701656s - PeerPollingThread: waiting 0.000s
151644 19:55:00.1701656s - PeerPollingThread: WaitTimeout
151644 19:55:00.1701656s - Reachability: Attempting to contact peer 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->38.229.71.1:123).
151644 19:55:00.1701656s - Polling peer 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->38.229.71.1:123)
151644 19:55:00.1701656s - Sending packet to 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->38.229.71.1:123) in Win2K detect mode, stage 1.
151644 19:55:00.1701656s - PeerPollingThread: PeerListUpdated
151644 19:55:00.1701656s - Peer poll: Max:900.0000000s (special) Cur:00.0000000s
151644 19:55:00.1701656s - Resolving manual peer: 1.pool.ntp.org,0x1
151644 19:55:00.1701656s - Resolving manual peer: 2.pool.ntp.org,0x1
151644 19:55:00.2170174s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
151644 19:55:00.2170174s - ListeningThread -- response heard from 38.229.71.1:123 <- 192.168.2.233:123
151644 19:55:00.2170174s - /-- NTP Packet:
151644 19:55:00.2170174s - | LeapIndicator: 0 - no warning;  VersionNumber: 3;  Mode: 2 - SymmetricPassive;  LiVnMode: 0x1A
151644 19:55:00.2170174s - | Stratum: 2 - secondary reference (syncd by (S)NTP)
151644 19:55:00.2170174s - | Poll Interval: 17 - out of valid range;  Precision: -19 - 1.90735æs per tick
151644 19:55:00.2170174s - | RootDelay: 0x0000.00E9s - 0.0035553s;  RootDispersion: 0x0000.09F6s - 0.0389099s
151644 19:55:00.2170174s - | ReferenceClockIdentifier: 0xCC093677 - source IP: 204.9.54.119
151644 19:55:00.2170174s - | ReferenceTimestamp:   0xDA8C4A77FCCAEC38 - 13102111991987471400ns - 151644 19:33:11.9874714s
151644 19:55:00.2170174s - | OriginateTimestamp:   0xDA8C4F942B8FF906 - 13102113300170165600ns - 151644 19:55:00.1701656s
151644 19:55:00.2170174s - | ReceiveTimestamp:     0xDA8C4F95D7BACAE3 - 13102113301842694000ns - 151644 19:55:01.8426940s
151644 19:55:00.2170174s - | TransmitTimestamp:    0xDA8C4F95D7BE9E82 - 13102113301842752400ns - 151644 19:55:01.8427524s
151644 19:55:00.2170174s - >-- Non-packet info:
151644 19:55:00.2170174s - | DestinationTimestamp: 151644 19:55:00.2170174s - 0xDA8C4F94378E73CB151644 19:55:00.2170174s -  - 13102113300217017400ns151644 19:55:00.2170174s -  - 151644 19:55:00.2170174s
151644 19:55:00.2170174s - | RoundtripDelay: 46793400ns (0s)
151644 19:55:00.2170174s - | LocalClockOffset: 1649131700ns - 0:01.649131700s
151644 19:55:00.2170174s - \--
151644 19:55:00.2170174s - Peer 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->38.229.71.1:123) is not Win2K. Setting compat flags.
151644 19:55:00.2170174s - Peer poll: Max:900.0000000s (special) Cur:899.9531482s
151644 19:55:00.2170174s - Response from peer 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->38.229.71.1:123), ofs: +01.6491317s
151644 19:55:00.2170174s - 5 Age:5 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000020s Dst:16.0000020s FDsp:08.0000000s
151644 19:55:00.2170174s - 4 Age:4 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000020s Dst:16.0000020s FDsp:12.0000000s
151644 19:55:00.2170174s - 3 Age:3 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000020s Dst:16.0000020s FDsp:14.0000000s
151644 19:55:00.2170174s - 2 Age:2 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000020s Dst:16.0000020s FDsp:15.0000000s
151644 19:55:00.2170174s - 1 Age:1 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000020s Dst:16.0000020s FDsp:15.5000000s
151644 19:55:00.2170174s - 0 Age:0 Ofs:+01.6491317s Dly:+00.0467934s RDly:+00.0035553s Dsp:00.0156274s RDsp:00.0389099s Pnt:00.0000000s Dst:00.0390241s FDsp:07.7500000s
151644 19:55:00.2170174s - Reachability:  peer 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->38.229.71.1:123) is reachable.
151644 19:55:00.2170174s - Logging information: NtpClient is currently receiving valid time data from 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->38.229.71.1:123).
151644 19:55:00.2170174s - PeerPollingThread: PeerListUpdated
151644 19:55:00.2170174s - Reachability:  removing peer 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->152.2.133.53:123).  
151644 19:55:00.2170174s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.2170174s - Reachability:  removing peer 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->131.107.13.100:123).  
151644 19:55:00.2170174s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.2170174s - Reachability:  removing peer 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->97.107.128.58:123).  
151644 19:55:00.2170174s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.2170174s - Resolving manual peer: 3.pool.ntp.org,0x1
151644 19:55:00.2170174s - W32TmServiceMain: resync req, irreg now pending.
151644 19:55:00.2170174s - W32TmServiceMain: waiting i0.000s (639.268s)
151644 19:55:00.2170174s - W32TmServiceMain: timeout
151644 19:55:00.2170174s - Sample Prepared at 131021133002170174 for peer 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->38.229.71.1:123)
151644 19:55:00.2170174s - NtpClient returned 1 samples.
151644 19:55:00.2170174s - Sample 0 offset:+01.6491317s delay:+00.0503487s dispersion:07.8045373s
151644 19:55:00.2170174s - Intersection successful with 0 dropped samples.
151644 19:55:00.2170174s -   0: Sample:0 SyncDist:398297116 SelectDisp:0
151644 19:55:00.2170174s - Sample 0 chosen. Select Dispersion:00.0000000s STC:79802
151644 19:55:00.2170174s - ClockDispln Update: SO:16491317 KPhO:0 PhO:16491317 uT:25653 SD:39022686 LI:0 S:3 RDl:503487 RDs:78145373 TSF:0x0 Unset->Hold
151644 19:55:00.2190372s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:45 CR:156250 PhCR:45 UI:360000 phcT:25653 KPhO:16491317
151644 19:55:00.2190372s - Logging information: The time service is now synchronizing the system time with the time source 0.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->38.229.71.1:123).
151644 19:55:00.2190372s - W32TmServiceMain: waiting 1024.000s
151644 19:55:00.2795339s - Association: (Local) 0.0.0.0:123 => 23.239.26.89:123 (Remote)
151644 19:55:00.2795339s - Association: (Local) 0.0.0.0:123 => 129.250.35.250:123 (Remote)
151644 19:55:00.2795339s - Association: (Local) 0.0.0.0:123 => 104.131.53.252:123 (Remote)
151644 19:55:00.2795339s - Association: (Local) 0.0.0.0:123 => 171.66.97.126:123 (Remote)
151644 19:55:00.2795339s - Created reachability group: (
151644 19:55:00.2795339s - 23.239.26.89:123,
151644 19:55:00.2795339s - 129.250.35.250:123,
151644 19:55:00.2795339s - 104.131.53.252:123,
151644 19:55:00.2795339s - 171.66.97.126:123,
151644 19:55:00.2795339s - )
151644 19:55:00.2795339s - PeerPollingThread: waiting 0.000s
151644 19:55:00.2795339s - PeerPollingThread: WaitTimeout
151644 19:55:00.2795339s - Reachability: Attempting to contact peer 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->23.239.26.89:123).
151644 19:55:00.2795339s - Polling peer 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->23.239.26.89:123)
151644 19:55:00.2795339s - Sending packet to 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->23.239.26.89:123) in Win2K detect mode, stage 1.
151644 19:55:00.2795339s - Peer poll: Max:900.0000000s (special) Cur:00.0000000s
151644 19:55:00.2795339s - PeerPollingThread: waiting 0.100s
151644 19:55:00.2795339s - PeerPollingThread: PeerListUpdated
151644 19:55:00.2795339s - PeerPollingThread: waiting 0.100s
151644 19:55:00.2795339s - PeerPollingThread: PeerListUpdated
151644 19:55:00.2795339s - PeerPollingThread: waiting 0.100s
151644 19:55:00.2951652s - Association: (Local) 0.0.0.0:123 => 199.102.46.79:123 (Remote)
151644 19:55:00.2951652s - Association: (Local) 0.0.0.0:123 => 138.236.128.112:123 (Remote)
151644 19:55:00.2951652s - Association: (Local) 0.0.0.0:123 => 129.6.15.29:123 (Remote)
151644 19:55:00.2951652s - Association: (Local) 0.0.0.0:123 => 209.244.0.3:123 (Remote)
151644 19:55:00.2951652s - Created reachability group: (
151644 19:55:00.2951652s - 199.102.46.79:123,
151644 19:55:00.2951652s - 138.236.128.112:123,
151644 19:55:00.2951652s - 129.6.15.29:123,
151644 19:55:00.2951652s - 209.244.0.3:123,
151644 19:55:00.2951652s - )
151644 19:55:00.2951652s - PeerPollingThread: waiting 0.000s
151644 19:55:00.2951652s - PeerPollingThread: WaitTimeout
151644 19:55:00.2951652s - Reachability: Attempting to contact peer 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->199.102.46.79:123).
151644 19:55:00.2951652s - Polling peer 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->199.102.46.79:123)
151644 19:55:00.2951652s - Sending packet to 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->199.102.46.79:123) in Win2K detect mode, stage 1.
151644 19:55:00.2951652s - Peer poll: Max:900.0000000s (special) Cur:00.0000000s
151644 19:55:00.2951652s - PeerPollingThread: waiting 0.085s
151644 19:55:00.2951652s - PeerPollingThread: PeerListUpdated
151644 19:55:00.2951652s - PeerPollingThread: waiting 0.085s
151644 19:55:00.2951652s - PeerPollingThread: PeerListUpdated
151644 19:55:00.2951652s - PeerPollingThread: waiting 0.085s
151644 19:55:00.3264232s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
151644 19:55:00.3264232s - ListeningThread -- response heard from 199.102.46.79:123 <- 192.168.2.233:123
151644 19:55:00.3264232s - /-- NTP Packet:
151644 19:55:00.3264232s - | LeapIndicator: 0 - no warning;  VersionNumber: 3;  Mode: 2 - SymmetricPassive;  LiVnMode: 0x1A
151644 19:55:00.3264232s - | Stratum: 1 - primary reference (syncd by radio clock)
151644 19:55:00.3264232s - | Poll Interval: 17 - out of valid range;  Precision: -20 - 953.674ns per tick
151644 19:55:00.3264232s - | RootDelay: 0x0000.0000s - unspecified;  RootDispersion: 0x0000.001Ds - 0.000442505s
151644 19:55:00.3264232s - | ReferenceClockIdentifier: 0x47505300 - source name: "GPS"
151644 19:55:00.3264232s - | ReferenceTimestamp:   0xDA8C4F871848D749 - 13102113287094861500ns - 151644 19:54:47.0948615s
151644 19:55:00.3264232s - | OriginateTimestamp:   0xDA8C4F944B8FF250 - 13102113300295165200ns - 151644 19:55:00.2951652s
151644 19:55:00.3264232s - | ReceiveTimestamp:     0xDA8C4F95F391BE1F - 13102113301951442600ns - 151644 19:55:01.9514426s
151644 19:55:00.3264232s - | TransmitTimestamp:    0xDA8C4F95F393070E - 13102113301951462200ns - 151644 19:55:01.9514622s
151644 19:55:00.3264232s - >-- Non-packet info:
151644 19:55:00.3264232s - | DestinationTimestamp: 151644 19:55:00.3264232s - 0xDA8C4F9453907888151644 19:55:00.3264232s -  - 13102113300326423200ns151644 19:55:00.3264232s -  - 151644 19:55:00.3264232s
151644 19:55:00.3264232s - | RoundtripDelay: 31238400ns (0s)
151644 19:55:00.3264232s - | LocalClockOffset: 1640658200ns - 0:01.640658200s
151644 19:55:00.3264232s - \--
151644 19:55:00.3264232s - Peer 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->199.102.46.79:123) is not Win2K. Setting compat flags.
151644 19:55:00.3264232s - Peer poll: Max:900.0000000s (special) Cur:899.9687420s
151644 19:55:00.3264232s - Response from peer 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->199.102.46.79:123), ofs: +01.6406582s
151644 19:55:00.3264232s - 5 Age:5 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:08.0000000s
151644 19:55:00.3264232s - 4 Age:4 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:12.0000000s
151644 19:55:00.3264232s - 3 Age:3 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:14.0000000s
151644 19:55:00.3264232s - 2 Age:2 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:15.0000000s
151644 19:55:00.3264232s - 1 Age:1 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:15.5000000s
151644 19:55:00.3264232s - 0 Age:0 Ofs:+01.6406582s Dly:+00.0312500s RDly:+00.0000000s Dsp:00.0156262s RDsp:00.0004425s Pnt:00.0000000s Dst:00.0312512s FDsp:07.7500000s
151644 19:55:00.3264232s - Reachability:  peer 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->199.102.46.79:123) is reachable.
151644 19:55:00.3264232s - Logging information: NtpClient is currently receiving valid time data from 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->199.102.46.79:123).
151644 19:55:00.3264232s - W32TmServiceMain: resync req, irreg now pending.
151644 19:55:00.3264232s - W32TmServiceMain: waiting i15.892s (1023.892s)
151644 19:55:00.3264232s - Association: (Local) 0.0.0.0:123 => 69.167.160.102:123 (Remote)
151644 19:55:00.3264232s - Association: (Local) 0.0.0.0:123 => 198.60.22.240:123 (Remote)
151644 19:55:00.3264232s - Association: (Local) 0.0.0.0:123 => 104.156.99.30:123 (Remote)
151644 19:55:00.3264232s - Association: (Local) 0.0.0.0:123 => 66.228.59.187:123 (Remote)
151644 19:55:00.3264232s - Created reachability group: (
151644 19:55:00.3264232s - 69.167.160.102:123,
151644 19:55:00.3264232s - 198.60.22.240:123,
151644 19:55:00.3264232s - 104.156.99.30:123,
151644 19:55:00.3264232s - 66.228.59.187:123,
151644 19:55:00.3264232s - )
151644 19:55:00.3264232s - PeerPollingThread: waiting 0.000s
151644 19:55:00.3264232s - PeerPollingThread: PeerListUpdated
151644 19:55:00.3264232s - Reachability:  removing peer 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->138.236.128.112:123).  
151644 19:55:00.3264232s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.3264232s - Reachability:  removing peer 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->129.6.15.29:123).  
151644 19:55:00.3264232s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.3264232s - Reachability:  removing peer 2.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->209.244.0.3:123).  
151644 19:55:00.3264232s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.3264232s - Reachability: Attempting to contact peer 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->69.167.160.102:123).
151644 19:55:00.3264232s - Polling peer 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->69.167.160.102:123)
151644 19:55:00.3264232s - PeerPollingThread: PeerListUpdated
151644 19:55:00.3264232s - Sending packet to 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->69.167.160.102:123) in Win2K detect mode, stage 1.
151644 19:55:00.3264232s - PeerPollingThread: waiting 0.054s
151644 19:55:00.3264232s - Peer poll: Max:900.0000000s (special) Cur:00.0000000s
151644 19:55:00.3264232s - PeerPollingThread: waiting 0.054s
151644 19:55:00.3420521s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
151644 19:55:00.3420521s - ListeningThread -- response heard from 23.239.26.89:123 <- 192.168.2.233:123
151644 19:55:00.3420521s - /-- NTP Packet:
151644 19:55:00.3420521s - | LeapIndicator: 0 - no warning;  VersionNumber: 3;  Mode: 2 - SymmetricPassive;  LiVnMode: 0x1A
151644 19:55:00.3420521s - | Stratum: 2 - secondary reference (syncd by (S)NTP)
151644 19:55:00.3420521s - | Poll Interval: 17 - out of valid range;  Precision: -23 - 119.209ns per tick
151644 19:55:00.3420521s - | RootDelay: 0x0000.065Cs - 0.0248413s;  RootDispersion: 0x0000.0885s - 0.0332794s
151644 19:55:00.3420521s - | ReferenceClockIdentifier: 0xD8E500B3 - source IP: 216.229.0.179
151644 19:55:00.3420521s - | ReferenceTimestamp:   0xDA8C4E703E28A24F - 13102113008242807500ns - 151644 19:50:08.2428075s
151644 19:55:00.3420521s - | OriginateTimestamp:   0xDA8C4F94478F889E - 13102113300279533900ns - 151644 19:55:00.2795339s
151644 19:55:00.3420521s - | ReceiveTimestamp:     0xDA8C4F95F61F1A15 - 13102113301961412100ns - 151644 19:55:01.9614121s
151644 19:55:00.3420521s - | TransmitTimestamp:    0xDA8C4F95F622D5A1 - 13102113301961469000ns - 151644 19:55:01.9614690s
151644 19:55:00.3420521s - >-- Non-packet info:
151644 19:55:00.3420521s - | DestinationTimestamp: 151644 19:55:00.3420521s - 0xDA8C4F945790B9F7151644 19:55:00.3420521s -  - 13102113300342052100ns151644 19:55:00.3420521s -  - 151644 19:55:00.3420521s
151644 19:55:00.3420521s - | RoundtripDelay: 62461300ns (0s)
151644 19:55:00.3420521s - | LocalClockOffset: 1650647500ns - 0:01.650647500s
151644 19:55:00.3420521s - \--
151644 19:55:00.3420521s - Peer 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->23.239.26.89:123) is not Win2K. Setting compat flags.
151644 19:55:00.3420521s - Peer poll: Max:900.0000000s (special) Cur:899.9374818s
151644 19:55:00.3420521s - Response from peer 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->23.239.26.89:123), ofs: +01.6506475s
151644 19:55:00.3420521s - 5 Age:5 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000028s Dst:16.0000028s FDsp:08.0000000s
151644 19:55:00.3420521s - 4 Age:4 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000028s Dst:16.0000028s FDsp:12.0000000s
151644 19:55:00.3420521s - 3 Age:3 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000028s Dst:16.0000028s FDsp:14.0000000s
151644 19:55:00.3420521s - 2 Age:2 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000028s Dst:16.0000028s FDsp:15.0000000s
151644 19:55:00.3420521s - 1 Age:1 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000028s Dst:16.0000028s FDsp:15.5000000s
151644 19:55:00.3420521s - 0 Age:0 Ofs:+01.6506475s Dly:+00.0624613s RDly:+00.0248413s Dsp:00.0156258s RDsp:00.0332794s Pnt:00.0000000s Dst:00.0468564s FDsp:07.7500000s
151644 19:55:00.3420521s - Reachability:  peer 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->23.239.26.89:123) is reachable.
151644 19:55:00.3420521s - Logging information: NtpClient is currently receiving valid time data from 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->23.239.26.89:123).
151644 19:55:00.3420521s - W32TmServiceMain: resync req, irreg already pending.
151644 19:55:00.3420521s - W32TmServiceMain: waiting i15.876s (1023.876s)
151644 19:55:00.3576823s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
151644 19:55:00.3576823s - ListeningThread -- response heard from 69.167.160.102:123 <- 192.168.2.233:123
151644 19:55:00.3576823s - /-- NTP Packet:
151644 19:55:00.3576823s - | LeapIndicator: 0 - no warning;  VersionNumber: 3;  Mode: 2 - SymmetricPassive;  LiVnMode: 0x1A
151644 19:55:00.3576823s - | Stratum: 2 - secondary reference (syncd by (S)NTP)
151644 19:55:00.3576823s - | Poll Interval: 17 - out of valid range;  Precision: -23 - 119.209ns per tick
151644 19:55:00.3576823s - | RootDelay: 0x0000.0B1Ds - 0.0434113s;  RootDispersion: 0x0000.0680s - 0.0253906s
151644 19:55:00.3576823s - | ReferenceClockIdentifier: 0xC63C4908 - source IP: 198.60.73.8
151644 19:55:00.3576823s - | ReferenceTimestamp:   0xDA8C4E9006CB4AB6 - 13102113040026539500ns - 151644 19:50:40.0265395s
151644 19:55:00.3576823s - | OriginateTimestamp:   0xDA8C4F9453907888 - 13102113300326423200ns - 151644 19:55:00.3264232s
151644 19:55:00.3576823s - | ReceiveTimestamp:     0xDA8C4F95FD200BE6 - 13102113301988770200ns - 151644 19:55:01.9887702s
151644 19:55:00.3576823s - | TransmitTimestamp:    0xDA8C4F95FD246E4C - 13102113301988837100ns - 151644 19:55:01.9888371s
151644 19:55:00.3576823s - >-- Non-packet info:
151644 19:55:00.3576823s - | DestinationTimestamp: 151644 19:55:00.3576823s - 0xDA8C4F945B911134151644 19:55:00.3576823s -  - 13102113300357682300ns151644 19:55:00.3576823s -  - 151644 19:55:00.3576823s
151644 19:55:00.3576823s - | RoundtripDelay: 31192200ns (0s)
151644 19:55:00.3576823s - | LocalClockOffset: 1646750900ns - 0:01.646750900s
151644 19:55:00.3576823s - \--
151644 19:55:00.3576823s - Peer 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->69.167.160.102:123) is not Win2K. Setting compat flags.
151644 19:55:00.3576823s - Peer poll: Max:900.0000000s (special) Cur:899.9687409s
151644 19:55:00.3576823s - Response from peer 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->69.167.160.102:123), ofs: +01.6467509s
151644 19:55:00.3576823s - 5 Age:5 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:08.0000000s
151644 19:55:00.3576823s - 4 Age:4 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:12.0000000s
151644 19:55:00.3576823s - 3 Age:3 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:14.0000000s
151644 19:55:00.3576823s - 2 Age:2 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:15.0000000s
151644 19:55:00.3576823s - 1 Age:1 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.0000012s Dst:16.0000012s FDsp:15.5000000s
151644 19:55:00.3576823s - 0 Age:0 Ofs:+01.6467509s Dly:+00.0312500s RDly:+00.0434113s Dsp:00.0156254s RDsp:00.0253906s Pnt:00.0000000s Dst:00.0312504s FDsp:07.7500000s
151644 19:55:00.3576823s - Reachability:  peer 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->69.167.160.102:123) is reachable.
151644 19:55:00.3576823s - Logging information: NtpClient is currently receiving valid time data from 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->69.167.160.102:123).
151644 19:55:00.3576823s - W32TmServiceMain: resync req, irreg already pending.
151644 19:55:00.3576823s - W32TmServiceMain: waiting i15.861s (1023.861s)
151644 19:55:00.3889440s - PeerPollingThread: WaitTimeout
151644 19:55:00.3889440s - Reachability:  removing peer 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->129.250.35.250:123).  
151644 19:55:00.3889440s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.3889440s - Reachability:  removing peer 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->104.131.53.252:123).  
151644 19:55:00.3889440s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.3889440s - Reachability:  removing peer 1.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->171.66.97.126:123).  
151644 19:55:00.3889440s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.3889440s - Reachability:  removing peer 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->198.60.22.240:123).  
151644 19:55:00.3889440s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.3889440s - Reachability:  removing peer 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->104.156.99.30:123).  
151644 19:55:00.3889440s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.3889440s - Reachability:  removing peer 3.pool.ntp.org,0x1 (ntp.m|0x1|0.0.0.0:123->66.228.59.187:123).  
151644 19:55:00.3889440s - *** Manual Peer timed out - other paths remain.
151644 19:55:00.3889440s - PeerPollingThread: waiting 899.782s

Open in new window

Author

Commented:
I have looked around, and it looks like not updating at startup is by design. If I set SpecialPollInterval to 900, it won't try to update time until the 900 seconds have run out, even with a restart in the middle of 900 seconds.

My concern is that this hyper-v vm will later be promoted to a DC, and I want to keep the time accurate, and if there was save instead of a shutdown (like the hyper-v host restarting and saving the DC vm), that time may become skewed.

In the meantime, I set a task when this vm starts to run w32tm /resync /rediscover at startup.

Does anyone see a problem arising from running w32time /resync /rediscover at startup as local service?
Small Business IT Consultant
Commented:
In the setting in vm manager on Hyper-V do you have the setting for time sync enabled--if so uncheck it: look under the mgmt section and integrated services
OWASP: Avoiding Hacker Tricks

Learn to build secure applications from the mindset of the hacker and avoid being exploited.

Author

Commented:
Yes, time sync is disabled for this vm in hyper-v settings
Lionel MMSmall Business IT Consultant
Commented:
give this a try
net stop w32time
w32tm /config /syncfromflags:manual /manualpeerlist:"time-a.nist.gov, time-b.nist.gov, time-c.nist.gov, time-d.nist.gov"
w32tm /config /reliable:yes
net start w32time

If you need to view the NTP configuration, type the following command from a prompt:
w32tm /query /configuration

Author

Commented:
Lionelmm's commands produce the same behavior, w32tm does not update time server upon startup, but only upon the timeout of SpecialPollInterval
Lionel MMSmall Business IT Consultant

Commented:
Please check your registry setting (regedit) see this link -- scroll down to about the middle of the page
Lionel MMSmall Business IT Consultant

Commented:
questioner was very engaged so I must assume this was a pressing issue for him/her and then stopped at the final suggestion -- so that must have worked and this is a viable solution for future questioners
https://www.experts-exchange.com/questions/28932243/Server-2012-W32time-NTP-synchronization-delay-Hyper-V.html#a41502695
https://www.experts-exchange.com/questions/28932243/Server-2012-W32time-NTP-synchronization-delay-Hyper-V.html#a41506658

Do more with

Expert Office
Submit tech questions to Ask the Experts™ at any time to receive solutions, advice, and new ideas from leading industry professionals.

Start 7-Day Free Trial